From 6aa4478c78cb34cf3d0ae5c752525110947bd247 Mon Sep 17 00:00:00 2001
From: Werner Koch <wk@gnupg.org>
Date: Wed, 27 Sep 2017 07:58:02 +0200
Subject: [PATCH] gpg: Let --debug clock time sign and verify.

* configure.ac (ENABLE_LOG_CLOCK): New ac_define and option.
* common/logging.c (log_clock): Use ENABLE_LOG_CLOCK to enable
timestamp printing.
* g10/call-agent.c (agent_pksign): Time signing.
* g10/sig-check.c (check_signature_end_simple): Time verification.
--

Timing for verification is limited to data signatures because this is
the most common thing to evaluate.  We should consider to change
log_clock to printf style so that we could print the signature class
and other info.

Signed-off-by: Werner Koch <wk@gnupg.org>
---
 common/logging.c | 12 ++++++------
 configure.ac     | 15 +++++++++++++++
 g10/call-agent.c |  6 ++++++
 g10/sig-check.c  |  4 ++++
 4 files changed, 31 insertions(+), 6 deletions(-)

diff --git a/common/logging.c b/common/logging.c
index c4eaca411..82b21e25b 100644
--- a/common/logging.c
+++ b/common/logging.c
@@ -1039,11 +1039,11 @@ log_printsexp () {}
 is found in sexputils.c
 */
 
-
+/* Print a microsecond timestamp followed by STRING.  */
 void
 log_clock (const char *string)
 {
-#if 0
+#if ENABLE_LOG_CLOCK
   static unsigned long long initial;
   struct timespec tv;
   unsigned long long now;
@@ -1060,10 +1060,10 @@ log_clock (const char *string)
     initial = now;
 
   log_debug ("[%6llu] %s", (now - initial)/1000, string);
-#else
-  /* You need to link with -ltr to enable the above code.  */
-  log_debug ("[not enabled in the source] %s", string);
-#endif
+#else /*!ENABLE_LOG_CLOCK*/
+  /* You may need to link with -ltr to use the above code.  */
+  log_debug ("[not enabled by configure] %s", string);
+#endif  /*!ENABLE_LOG_CLOCK*/
 }
 
 
diff --git a/configure.ac b/configure.ac
index b43cb60b4..c479325e4 100644
--- a/configure.ac
+++ b/configure.ac
@@ -1679,6 +1679,21 @@ AC_ARG_ENABLE(optimization,
                       CFLAGS=`echo $CFLAGS | sed s/-O[[1-9]]\ /-O0\ /g`
                    fi])
 
+#
+# log_debug has certain requirements which might hamper portability.
+# Thus we use an option to enable it.
+#
+AC_MSG_CHECKING([whether to enable log_clock])
+AC_ARG_ENABLE(log_clock,
+              AC_HELP_STRING([--enable-log-clock],
+                             [enable log_clock timestamps]),
+              enable_log_clock=$enableval, enable_log_clock=no)
+AC_MSG_RESULT($enable_log_clock)
+if test "$enable_log_clock" = yes ; then
+  AC_DEFINE(ENABLE_LOG_CLOCK,1,[Defined to use log_clock timestamps])
+fi
+
+
 #
 # Configure option --enable-all-tests
 #
diff --git a/g10/call-agent.c b/g10/call-agent.c
index 545b2448a..3874ac181 100644
--- a/g10/call-agent.c
+++ b/g10/call-agent.c
@@ -1854,10 +1854,16 @@ agent_pksign (ctrl_t ctrl, const char *cache_nonce,
   snprintf (line, sizeof line, "PKSIGN%s%s",
             cache_nonce? " -- ":"",
             cache_nonce? cache_nonce:"");
+
+  if (DBG_CLOCK)
+    log_clock ("enter signing");
   err = assuan_transact (agent_ctx, line,
                          put_membuf_cb, &data,
                          default_inq_cb, &dfltparm,
                          NULL, NULL);
+  if (DBG_CLOCK)
+    log_clock ("leave signing");
+
   if (err)
     xfree (get_membuf (&data, NULL));
   else
diff --git a/g10/sig-check.c b/g10/sig-check.c
index 23af12b2e..63c38a64a 100644
--- a/g10/sig-check.c
+++ b/g10/sig-check.c
@@ -510,7 +510,11 @@ check_signature_end_simple (PKT_public_key *pk, PKT_signature *sig,
         return GPG_ERR_GENERAL;
 
     /* Verify the signature.  */
+    if (DBG_CLOCK && sig->sig_class <= 0x01)
+      log_clock ("enter pk_verify");
     rc = pk_verify( pk->pubkey_algo, result, sig->data, pk->pkey );
+    if (DBG_CLOCK && sig->sig_class <= 0x01)
+      log_clock ("leave pk_verify");
     gcry_mpi_release (result);
 
     if( !rc && sig->flags.unknown_critical )