core: Switch to logging via gpgrt

* src/debug.c (errfp): Remove.
(debug_init): Factor some code out to ...
(safe_to_use_debug_file): new.
(tid_log_callback): New.
(debug_init): Rewrite to make use of gpgrt logging.
(_gpgme_debug): Ditto.
(_gpgme_debug_end): Remove extra LF testing code.
* src/dirinfo.c (get_gpgconf_item): Remove now unneeded LFs.  Realign
output.

doc/gpgme.texi

@@ -7935,6 +7935,15 @@ reveal sensitive details like passphrases or other data you use in
 your application.  If you are asked to send a log file, make sure that
 you run your tests only with play data.
 
+The trace function makes use of gpgrt's logging function and thus the
+special @file{socket://} and @file{tcp://} files may be used.  Because
+this conflicts with the use of colons to separate fields, the following
+hack is used: If the file name contains the string @code{^//} all
+carets are replaced by colons.  For example to log to TCP port 42042
+this can be used:
+@smallexample
+GPGME_DEBUG=5:tcp^//127.0.0.1^42042
+@end smallexample
 
 @node Deprecated Functions
 @appendix Deprecated Functions

src/debug.c

@@ -1,6 +1,6 @@
 /* debug.c - helpful output in desperate situations
  * Copyright (C) 2000 Werner Koch (dd9jn)
- * Copyright (C) 2001, 2002, 2003, 2004, 2005, 2007, 2009, 2019 g10 Code GmbH
+ * Copyright (C) 2001-2005, 2007, 2009, 2019-2023 g10 Code GmbH
  *
  * This file is part of GPGME.
  *
@@ -54,9 +54,6 @@
    variable GPGME_DEBUG.  */
 static int debug_level;
 
-/* The output stream for the debug messages.  */
-static FILE *errfp;
-
 /* If not NULL, this malloced string is used instead of the
    GPGME_DEBUG envvar.  It must have been set before the debug
    subsystem has been initialized.  Using it later may or may not have
@@ -126,6 +123,37 @@ _gpgme_debug_set_debug_envvar (const char *value)
 }
 
 
+static int
+safe_to_use_debug_file (void)
+{
+#ifdef HAVE_DOSISH_SYSTEM
+  return 1;
+#else /* Unix */
+  return (getuid () == geteuid ()
+#if defined(HAVE_GETGID) && defined(HAVE_GETEGID)
+          && getgid () == getegid ()
+#endif
+          );
+#endif /* Unix */
+}
+
+
+static int
+tid_log_callback (unsigned long *rvalue)
+{
+  int len = sizeof (*rvalue);
+  uintptr_t thread;
+
+  thread = ath_self ();
+  if (sizeof (thread) < len)
+    len = sizeof (thread);
+  memcpy (rvalue, &thread, len);
+
+  return 2; /* Use use hex representation.  */
+}
+
+
+
 static void
 debug_init (void)
 {
@@ -135,7 +163,7 @@ debug_init (void)
     {
       gpgme_error_t err;
       char *e;
-      const char *s1, *s2;;
+      const char *s1, *s2;
 
       if (envvar_override)
         {
@@ -151,24 +179,15 @@ debug_init (void)
         }
 
       initialized = 1;
-      errfp = stderr;
       if (e)
 	{
+          char *p, *r;
+          unsigned int flags;
+
 	  debug_level = atoi (e);
           s1 = strchr (e, PATHSEP_C);
-	  if (s1)
+          if (s1 && safe_to_use_debug_file ())
             {
-#ifndef HAVE_DOSISH_SYSTEM
-	      if (getuid () == geteuid ()
-#if defined(HAVE_GETGID) && defined(HAVE_GETEGID)
-                  && getgid () == getegid ()
-#endif
-                  )
-		{
-#endif
-		  char *p;
-		  FILE *fp;
-
               s1++;
               if (!(s2 = strchr (s1, PATHSEP_C)))
                 s2 = s1 + strlen (s1);
@@ -178,31 +197,39 @@ debug_init (void)
                   memcpy (p, s1, s2 - s1);
                   p[s2-s1] = 0;
                   trim_spaces (p);
-		      fp = fopen (p,"a");
+                  if (strstr (p, "^//"))
-		      if (fp)
                     {
-			  setvbuf (fp, NULL, _IOLBF, 0);
+                      /* map chars to allow socket: and tcp: */
-			  errfp = fp;
+                      for (r=p; *r; r++)
+                        if (*r == '^')
+                          *r = ':';
                     }
+                  if (*p)
+                    gpgrt_log_set_sink (p, NULL, -1);
                   free (p);
                 }
-#ifndef HAVE_DOSISH_SYSTEM
-		}
-#endif
             }
 	  free (e);
+
+          gpgrt_log_get_prefix (&flags);
+          flags |= (GPGRT_LOG_WITH_PREFIX
+                    | GPGRT_LOG_WITH_TIME
+                    | GPGRT_LOG_WITH_PID);
+          gpgrt_log_set_prefix (*gpgrt_log_get_prefix (NULL)?NULL:"gpgme",
+                                flags);
+          gpgrt_log_set_pid_suffix_cb (tid_log_callback);
         }
     }
 
   if (debug_level > 0)
     {
       _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL,
-                    "gpgme_debug: level=%d\n", debug_level);
+                    "gpgme_debug: level=%d", debug_level);
 #ifdef HAVE_W32_SYSTEM
       {
         const char *name = _gpgme_get_inst_dir ();
         _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL,
-                      "gpgme_debug: gpgme='%s'\n", name? name: "?");
+                      "gpgme_debug: gpgme='%s'", name? name: "?");
       }
 #endif
     }
@@ -250,9 +277,8 @@ _gpgme_debug (void **line, int level, int mode,
 {
   va_list arg_ptr;
   int saved_errno;
-  int need_lf;
   int indent;
-  char *prefix, *stdinfo, *userinfo;
+  char *stdinfo, *userinfo;
   const char *modestr;
   int no_userinfo = 0;
 
@@ -267,17 +293,6 @@ _gpgme_debug (void **line, int level, int mode,
 
   saved_errno = errno;
   va_start (arg_ptr, format);
-  {
-    struct tm *tp;
-    time_t atime = time (NULL);
-
-    tp = localtime (&atime);
-    prefix = gpgrt_bsprintf ("GPGME %04d%02d%02dT%02d%02d%02d %04llX  %*s",
-                             1900+tp->tm_year, tp->tm_mon+1, tp->tm_mday,
-                             tp->tm_hour, tp->tm_min, tp->tm_sec,
-                             (unsigned long long) ath_self (),
-                             indent < 40? indent : 40, "");
-  }
 
   switch (mode)
     {
@@ -305,33 +320,25 @@ _gpgme_debug (void **line, int level, int mode,
     }
   va_end (arg_ptr);
 
-  if (mode != -1 && (!format || !*format))
-    need_lf = 1;
-  else if (userinfo && *userinfo && userinfo[strlen (userinfo) - 1] != '\n')
-    need_lf = 1;
-  else
-    need_lf = 0;
-
   if (line)
-    *line = gpgrt_bsprintf ("%s%s%s",
+    *line = gpgrt_bsprintf ("%s%s",
-                            prefix? prefix : "GPGME out-of-core ",
+                            (!modestr ? "" :
-                            !modestr? "" : stdinfo? stdinfo :
+                             stdinfo  ? stdinfo :
-                            (!format || !*format)? "" :"out-of-core ",
+                             (!format || !*format)? "" :"out-of-core "),
                             userinfo? userinfo : "out-of-core");
   else
     {
-      fprintf (errfp, "%s%s%s%s",
+      gpgrt_log (GPGRT_LOGLVL_INFO, "%*s%s%s",
-               prefix? prefix : "GPGME out-of-core ",
+                 indent < 40? indent : 40, "",
-               !modestr? "" : stdinfo? stdinfo :
+                 (!modestr ? "" :
-               (!format || !*format)? "" :"out-of-core ",
+                  stdinfo  ? stdinfo :
-               userinfo? userinfo : no_userinfo? "" : "out-of-core",
+                  (!format || !*format)? "" : "out-of-core "),
-               need_lf? "\n":"");
+                 (userinfo? userinfo :
-      fflush (errfp);
+                  no_userinfo? "" : "out-of-core"));
     }
 
   gpgrt_free (userinfo);
   gpgrt_free (stdinfo);
-  gpgrt_free (prefix);
   gpg_err_set_errno (saved_errno);
   return 0;
 }
@@ -378,10 +385,7 @@ _gpgme_debug_end (void **line)
     return;
   string = *line;
 
-  fprintf (errfp, "%s%s",
+  gpgrt_log (GPGRT_LOGLVL_INFO, "%s", string);
-           string,
-           (*string && string[strlen (string)-1] != '\n')? "\n":"");
-  fflush (errfp);
   gpgrt_free (*line);
   *line = NULL;
 }

src/dirinfo.c

@@ -289,13 +289,13 @@ get_gpgconf_item (int what)
       if (pgmname && _gpgme_access (pgmname, F_OK))
         {
           _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL,
-                        "gpgme-dinfo: gpgconf='%s' [not installed]\n", pgmname);
+                        "gpgme-dinfo: gpgconf='%s' [not installed]", pgmname);
           free (pgmname);
           pgmname = NULL; /* Not available.  */
         }
       else
         _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL,
-                      "gpgme-dinfo: gpgconf='%s'\n",
+                      "gpgme-dinfo: gpgconf='%s'",
                       pgmname? pgmname : "[null]");
       if (!pgmname)
         {
@@ -322,59 +322,59 @@ get_gpgconf_item (int what)
       dirinfo.valid = 1;
       if (dirinfo.gpg_name)
         _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL,
-                      "gpgme-dinfo:     gpg='%s'\n",
+                      "gpgme-dinfo:       gpg='%s'",
                       dirinfo.gpg_name);
       if (dirinfo.g13_name)
         _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL,
-                      "gpgme-dinfo:     g13='%s'\n",
+                      "gpgme-dinfo:       g13='%s'",
                       dirinfo.g13_name);
       if (dirinfo.gpgsm_name)
         _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL,
-                      "gpgme-dinfo:   gpgsm='%s'\n",
+                      "gpgme-dinfo:     gpgsm='%s'",
                       dirinfo.gpgsm_name);
       if (dirinfo.keyboxd_name)
         _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL,
-                      "gpgme-dinfo:     keyboxd='%s'\n",
+                      "gpgme-dinfo:   keyboxd='%s'",
                       dirinfo.keyboxd_name);
       if (dirinfo.agent_name)
         _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL,
-                      "gpgme-dinfo:     gpg-agent='%s'\n",
+                      "gpgme-dinfo: gpg-agent='%s'",
                       dirinfo.agent_name);
       if (dirinfo.scdaemon_name)
         _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL,
-                      "gpgme-dinfo:     scdaemon='%s'\n",
+                      "gpgme-dinfo:  scdaemon='%s'",
                       dirinfo.scdaemon_name);
       if (dirinfo.dirmngr_name)
         _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL,
-                      "gpgme-dinfo:     dirmngr='%s'\n",
+                      "gpgme-dinfo:   dirmngr='%s'",
                       dirinfo.dirmngr_name);
       if (dirinfo.pinentry_name)
         _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL,
-                      "gpgme-dinfo:     pinentry='%s'\n",
+                      "gpgme-dinfo:  pinentry='%s'",
                       dirinfo.pinentry_name);
       if (dirinfo.homedir)
         _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL,
-                      "gpgme-dinfo: homedir='%s'\n",
+                      "gpgme-dinfo:   homedir='%s'",
                       dirinfo.homedir);
       if (dirinfo.socketdir)
         _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL,
-                      "gpgme-dinfo: sockdir='%s'\n",
+                      "gpgme-dinfo:   sockdir='%s'",
                       dirinfo.socketdir);
       if (dirinfo.agent_socket)
-        _gpgme_debug (NULL,DEBUG_INIT, -1, NULL, NULL, NULL,
+        _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL,
-                      "gpgme-dinfo:   agent='%s'\n",
+                      "gpgme-dinfo:     agent='%s'",
                       dirinfo.agent_socket);
       if (dirinfo.agent_ssh_socket)
         _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL,
-                      "gpgme-dinfo:     ssh='%s'\n",
+                      "gpgme-dinfo:       ssh='%s'",
                       dirinfo.agent_ssh_socket);
       if (dirinfo.dirmngr_socket)
         _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL,
-                      "gpgme-dinfo: dirmngr='%s'\n",
+                      "gpgme-dinfo:   dirmngr='%s'",
                       dirinfo.dirmngr_socket);
       if (dirinfo.uisrv_socket)
         _gpgme_debug (NULL, DEBUG_INIT, -1, NULL, NULL, NULL,
-                      "gpgme-dinfo:   uisrv='%s'\n",
+                      "gpgme-dinfo:     uisrv='%s'",
                       dirinfo.uisrv_socket);
     }
   switch (what)