Debug: provide for SIGALRM tracking

20 files changed, 74 insertions, 56 deletions

diff --git a/src/src/child.c b/src/src/child.c
index fb333d3a4..085f26600 100644
--- a/src/src/child.c
+++ b/src/src/child.c
@@ -507,7 +507,7 @@ int yield;
 if (timeout > 0)
   {
   sigalrm_seen = FALSE;
-  alarm(timeout);
+  ALARM(timeout);
   }
 
 for(;;)
@@ -528,7 +528,7 @@ for(;;)
     }
   }
 
-if (timeout > 0) alarm(0);
+if (timeout > 0) ALARM_CLR(0);
 
 signal(SIGCHLD, oldsignal);   /* restore */
 return yield;
diff --git a/src/src/daemon.c b/src/src/daemon.c
index 66787896b..d69a7db3d 100644
--- a/src/src/daemon.c
+++ b/src/src/daemon.c
@@ -1787,7 +1787,7 @@ for (;;)
         }
 
       sigalrm_seen = FALSE;
-      alarm(resignal_interval);
+      ALARM(resignal_interval);
       }
 
     else
@@ -1900,7 +1900,7 @@ for (;;)
       /* Reset the alarm clock */
 
       sigalrm_seen = FALSE;
-      alarm(queue_interval);
+      ALARM(queue_interval);
       }
 
     } /* sigalrm_seen */
@@ -2087,7 +2087,7 @@ for (;;)
       getpid());
     for (sk = 0; sk < listen_socket_count; sk++)
       (void)close(listen_sockets[sk]);
-    alarm(0);
+    ALARM_CLR(0);
     signal(SIGHUP, SIG_IGN);
     sighup_argv[0] = exim_path;
     exim_nullstd();
diff --git a/src/src/dbfn.c b/src/src/dbfn.c
index 25c1a3fba..336cfe73e 100644
--- a/src/src/dbfn.c
+++ b/src/src/dbfn.c
@@ -137,9 +137,9 @@ DEBUG(D_hints_lookup|D_retry|D_route|D_deliver)
   debug_printf_indent("locking %s\n", filename);
 
 sigalrm_seen = FALSE;
-alarm(EXIMDB_LOCK_TIMEOUT);
+ALARM(EXIMDB_LOCK_TIMEOUT);
 rc = fcntl(dbblock->lockfd, F_SETLKW, &lock_data);
-alarm(0);
+ALARM_CLR(0);
 
 if (sigalrm_seen) errno = ETIMEDOUT;
 if (rc < 0)
diff --git a/src/src/dummies.c b/src/src/dummies.c
index d176befe8..ab821f1ac 100644
--- a/src/src/dummies.c
+++ b/src/src/dummies.c
@@ -100,7 +100,7 @@ void
 sigalrm_handler(int sig)
 {
 sig = sig;            /* Keep picky compilers happy */
-sigalrm_seen = 1;
+sigalrm_seen = TRUE;
 }
 
 
diff --git a/src/src/exim_dbutil.c b/src/src/exim_dbutil.c
index a33c59c08..45bad208c 100644
--- a/src/src/exim_dbutil.c
+++ b/src/src/exim_dbutil.c
@@ -284,9 +284,9 @@ lock_data.l_whence = lock_data.l_start = lock_data.l_len = 0;
 
 sigalrm_seen = FALSE;
 os_non_restarting_signal(SIGALRM, sigalrm_handler);
-alarm(EXIMDB_LOCK_TIMEOUT);
+ALARM(EXIMDB_LOCK_TIMEOUT);
 rc = fcntl(dbblock->lockfd, F_SETLKW, &lock_data);
-alarm(0);
+ALARM_CLR(0);
 
 if (sigalrm_seen) errno = ETIMEDOUT;
 if (rc < 0)
diff --git a/src/src/expand.c b/src/src/expand.c
index f32425b3f..5054e151b 100644
--- a/src/src/expand.c
+++ b/src/src/expand.c
@@ -5051,9 +5051,9 @@ while (*s != 0)
 	  server_name = US sockun.sun_path;
 
           sigalrm_seen = FALSE;
-          alarm(timeout);
+          ALARM(timeout);
           rc = connect(fd, (struct sockaddr *)(&sockun), sizeof(sockun));
-          alarm(0);
+          ALARM_CLR(0);
           if (sigalrm_seen)
             {
             expand_string_message = US "socket connect timed out";
@@ -5126,13 +5126,13 @@ while (*s != 0)
 	if (!tls_ctx)
 	  fp = fdopen(fd, "rb");
         sigalrm_seen = FALSE;
-        alarm(timeout);
+        ALARM(timeout);
         yield =
 #ifdef SUPPORT_TLS
 	  tls_ctx ? cat_file_tls(tls_ctx, yield, sub_arg[3]) :
 #endif
 		    cat_file(fp, yield, sub_arg[3]);
-        alarm(0);
+        ALARM_CLR(0);
 
 #ifdef SUPPORT_TLS
 	if (tls_ctx)
@@ -5265,9 +5265,9 @@ while (*s != 0)
 	resetok = FALSE;
         f = fdopen(fd_out, "rb");
         sigalrm_seen = FALSE;
-        alarm(60);
+        ALARM(60);
 	lookup_value = string_from_gstring(cat_file(f, NULL, NULL));
-        alarm(0);
+        ALARM_CLR(0);
         (void)fclose(f);
 
         /* Wait for the process to finish, applying the timeout, and inspect its
diff --git a/src/src/globals.c b/src/src/globals.c
index fdeaebd64..f8a4c3c0d 100644
--- a/src/src/globals.c
+++ b/src/src/globals.c
@@ -1417,6 +1417,7 @@ int     sender_verified_rc     = -1;
 uschar *sending_ip_address     = NULL;
 int     sending_port           = -1;
 SIGNAL_BOOL sigalrm_seen       = FALSE;
+const uschar *sigalarm_setter  = NULL;
 uschar **sighup_argv           = NULL;
 int     slow_lookup_log        = 0;	/* millisecs, zero disables */
 int     smtp_accept_count      = 0;
diff --git a/src/src/globals.h b/src/src/globals.h
index de0a7bab8..d337d3b75 100644
--- a/src/src/globals.h
+++ b/src/src/globals.h
@@ -871,6 +871,7 @@ extern address_item *sender_verified_failed; /* The one that caused denial */
 extern uschar *sending_ip_address;     /* Address of outgoing (SMTP) interface */
 extern int     sending_port;           /* Port of outgoing interface */
 extern SIGNAL_BOOL sigalrm_seen;       /* Flag for sigalrm_handler */
+extern const uschar *sigalarm_setter;  /* For debug, set to callpoint of alarm() */
 extern uschar **sighup_argv;           /* Args for re-execing after SIGHUP */
 extern int     slow_lookup_log;        /* Log DNS lookups taking longer than N millisecs */
 extern int     smtp_accept_count;      /* Count of connections */
diff --git a/src/src/ip.c b/src/src/ip.c
index ef133bf9f..fa688be64 100644
--- a/src/src/ip.c
+++ b/src/src/ip.c
@@ -243,7 +243,7 @@ timer, thereby allowing the inbuilt OS timeout to operate. */
 
 callout_address = string_sprintf("[%s]:%d", address, port);
 sigalrm_seen = FALSE;
-if (timeout > 0) alarm(timeout);
+if (timeout > 0) ALARM(timeout);
 
 #if defined(TCP_FASTOPEN) && defined(MSG_FASTOPEN)
 /* TCP Fast Open, if the system has a cookie from a previous call to
@@ -307,7 +307,7 @@ legacy_connect:
   }
 
 save_errno = errno;
-alarm(0);
+ALARM_CLR(0);
 
 /* There is a testing facility for simulating a connection timeout, as I
 can't think of any other way of doing this. It converts a connection refused
diff --git a/src/src/macros.h b/src/src/macros.h
index 0d979d0c8..2e4f6c45c 100644
--- a/src/src/macros.h
+++ b/src/src/macros.h
@@ -1047,4 +1047,20 @@ enum { FILTER_UNSET, FILTER_FORWARD, FILTER_EXIM, FILTER_SIEVE };
 #define TLS_SHUTDOWN_WAIT	2
 
 
+#ifdef COMPILE_UTILITY
+# define ALARM(seconds) alarm(seconds);
+# define ALARM_CLR(seconds) alarm(seconds);
+#else
+/* For debugging of odd alarm-signal problems, stash caller info while the
+alarm is active.  Clear it down on cancelling the alarm so we can tell there
+should not be one active. */
+
+# define ALARM(seconds) \
+    debug_selector & D_any \
+    ? (sigalarm_setter = CCS __FUNCTION__, alarm(seconds)) : alarm(seconds);
+# define ALARM_CLR(seconds) \
+    debug_selector & D_any \
+    ? (sigalarm_setter = NULL, alarm(seconds)) : alarm(seconds);
+#endif
+
 /* End of macros.h */
diff --git a/src/src/os.c b/src/src/os.c
index 6e88b844a..5ce56b515 100644
--- a/src/src/os.c
+++ b/src/src/os.c
@@ -922,7 +922,7 @@ int rc;
 printf("Testing restarting signal; wait for handler message, then type a line\n");
 strcpy(buffer, "*** default ***\n");
 os_restarting_signal(SIGALRM, sigalrm_handler);
-alarm(2);
+ALARM(2);
 if ((rc = read(fd, buffer, sizeof(buffer))) < 0)
   printf("No data read\n");
 else
@@ -930,12 +930,12 @@ else
   buffer[rc] = 0;
   printf("Read: %s", buffer);
   }
-alarm(0);
+ALARM_CLR(0);
 
 printf("Testing non-restarting signal; should read no data after handler message\n");
 strcpy(buffer, "*** default ***\n");
 os_non_restarting_signal(SIGALRM, sigalrm_handler);
-alarm(2);
+ALARM(2);
 if ((rc = read(fd, buffer, sizeof(buffer))) < 0)
   printf("No data read\n");
 else
@@ -943,7 +943,7 @@ else
   buffer[rc] = 0;
   printf("Read: %s", buffer);
   }
-alarm(0);
+ALARM_CLR(0);
 
 printf("Testing load averages (last test - ^C to kill)\n");
 for (;;)
diff --git a/src/src/rda.c b/src/src/rda.c
index 8962dbaec..4131ac612 100644
--- a/src/src/rda.c
+++ b/src/src/rda.c
@@ -110,7 +110,7 @@ if (saved_errno == ENOENT)
   slash = Ustrrchr(big_buffer, '/');
   Ustrcpy(slash+1, ".");
 
-  alarm(30);
+  ALARM(30);
   rc = Ustat(big_buffer, &statbuf);
   if (rc != 0 && errno == EACCES && !sigalrm_seen)
     {
@@ -118,7 +118,7 @@ if (saved_errno == ENOENT)
     rc = Ustat(big_buffer, &statbuf);
     }
   saved_errno = errno;
-  alarm(0);
+  ALARM_CLR(0);
 
   DEBUG(D_route) debug_printf("stat(%s)=%d\n", big_buffer, rc);
   }
diff --git a/src/src/receive.c b/src/src/receive.c
index 016a92d6b..cd7867d04 100644
--- a/src/src/receive.c
+++ b/src/src/receive.c
@@ -1764,7 +1764,7 @@ single timeout for the whole message. */
 else if (receive_timeout > 0)
   {
   os_non_restarting_signal(SIGALRM, data_timeout_handler);
-  alarm(receive_timeout);
+  ALARM(receive_timeout);
   }
 
 /* SIGTERM and SIGINT are caught always. */
@@ -3657,9 +3657,9 @@ if (sigsetjmp(local_scan_env, 1) == 0)
 
   had_local_scan_timeout = 0;
   os_non_restarting_signal(SIGALRM, local_scan_timeout_handler);
-  if (local_scan_timeout > 0) alarm(local_scan_timeout);
+  if (local_scan_timeout > 0) ALARM(local_scan_timeout);
   rc = local_scan(data_fd, &local_scan_data);
-  alarm(0);
+  ALARM_CLR(0);
   os_non_restarting_signal(SIGALRM, sigalrm_handler);
 
   f.enable_dollar_recipients = FALSE;
diff --git a/src/src/smtp_in.c b/src/src/smtp_in.c
index 00c842760..8c1d3111c 100644
--- a/src/src/smtp_in.c
+++ b/src/src/smtp_in.c
@@ -499,14 +499,14 @@ smtp_refill(unsigned lim)
 int rc, save_errno;
 if (!smtp_out) return FALSE;
 fflush(smtp_out);
-if (smtp_receive_timeout > 0) alarm(smtp_receive_timeout);
+if (smtp_receive_timeout > 0) ALARM(smtp_receive_timeout);
 
 /* Limit amount read, so non-message data is not fed to DKIM.
 Take care to not touch the safety NUL at the end of the buffer. */
 
 rc = read(fileno(smtp_in), smtp_inbuffer, MIN(IN_BUFFER_SIZE-1, lim));
 save_errno = errno;
-if (smtp_receive_timeout > 0) alarm(0);
+if (smtp_receive_timeout > 0) ALARM_CLR(0);
 if (rc <= 0)
   {
   /* Must put the error text in fixed store, because this might be during
diff --git a/src/src/tls-gnu.c b/src/src/tls-gnu.c
index 86d005d68..50554f215 100644
--- a/src/src/tls-gnu.c
+++ b/src/src/tls-gnu.c
@@ -2101,11 +2101,11 @@ state->fd_in = fileno(smtp_in);
 state->fd_out = fileno(smtp_out);
 
 sigalrm_seen = FALSE;
-if (smtp_receive_timeout > 0) alarm(smtp_receive_timeout);
+if (smtp_receive_timeout > 0) ALARM(smtp_receive_timeout);
 do
   rc = gnutls_handshake(state->session);
 while (rc == GNUTLS_E_AGAIN ||  rc == GNUTLS_E_INTERRUPTED && !sigalrm_seen);
-alarm(0);
+ALARM_CLR(0);
 
 if (rc != GNUTLS_E_SUCCESS)
   {
@@ -2427,11 +2427,11 @@ DEBUG(D_tls) debug_printf("about to gnutls_handshake\n");
 /* There doesn't seem to be a built-in timeout on connection. */
 
 sigalrm_seen = FALSE;
-alarm(ob->command_timeout);
+ALARM(ob->command_timeout);
 do
   rc = gnutls_handshake(state->session);
 while (rc == GNUTLS_E_AGAIN || rc == GNUTLS_E_INTERRUPTED && !sigalrm_seen);
-alarm(0);
+ALARM_CLR(0);
 
 if (rc != GNUTLS_E_SUCCESS)
   {
@@ -2530,9 +2530,9 @@ if (shutdown)
   DEBUG(D_tls) debug_printf("tls_close(): shutting down TLS%s\n",
     shutdown > 1 ? " (with response-wait)" : "");
 
-  alarm(2);
+  ALARM(2);
   gnutls_bye(state->session, shutdown > 1 ? GNUTLS_SHUT_RDWR : GNUTLS_SHUT_WR);
-  alarm(0);
+  ALARM_CLR(0);
   }
 
 gnutls_deinit(state->session);
@@ -2558,10 +2558,10 @@ DEBUG(D_tls) debug_printf("Calling gnutls_record_recv(%p, %p, %u)\n",
   state->session, state->xfer_buffer, ssl_xfer_buffer_size);
 
 sigalrm_seen = FALSE;
-if (smtp_receive_timeout > 0) alarm(smtp_receive_timeout);
+if (smtp_receive_timeout > 0) ALARM(smtp_receive_timeout);
 inbytes = gnutls_record_recv(state->session, state->xfer_buffer,
   MIN(ssl_xfer_buffer_size, lim));
-if (smtp_receive_timeout > 0) alarm(0);
+if (smtp_receive_timeout > 0) ALARM_CLR(0);
 
 if (had_command_timeout)		/* set by signal handler */
   smtp_command_timeout_exit();		/* does not return */
diff --git a/src/src/tls-openssl.c b/src/src/tls-openssl.c
index cda31f140..28e37e6d7 100644
--- a/src/src/tls-openssl.c
+++ b/src/src/tls-openssl.c
@@ -2263,9 +2263,9 @@ SSL_set_accept_state(server_ssl);
 DEBUG(D_tls) debug_printf("Calling SSL_accept\n");
 
 sigalrm_seen = FALSE;
-if (smtp_receive_timeout > 0) alarm(smtp_receive_timeout);
+if (smtp_receive_timeout > 0) ALARM(smtp_receive_timeout);
 rc = SSL_accept(server_ssl);
-alarm(0);
+ALARM_CLR(0);
 
 if (rc <= 0)
   {
@@ -2643,9 +2643,9 @@ client_static_cbinfo->event_action = tb ? tb->event_action : NULL;
 
 DEBUG(D_tls) debug_printf("Calling SSL_connect\n");
 sigalrm_seen = FALSE;
-alarm(ob->command_timeout);
+ALARM(ob->command_timeout);
 rc = SSL_connect(exim_client_ctx->ssl);
-alarm(0);
+ALARM_CLR(0);
 
 #ifdef SUPPORT_DANE
 if (tlsa_dnsa)
@@ -2689,11 +2689,11 @@ int inbytes;
 DEBUG(D_tls) debug_printf("Calling SSL_read(%p, %p, %u)\n", server_ssl,
   ssl_xfer_buffer, ssl_xfer_buffer_size);
 
-if (smtp_receive_timeout > 0) alarm(smtp_receive_timeout);
+if (smtp_receive_timeout > 0) ALARM(smtp_receive_timeout);
 inbytes = SSL_read(server_ssl, CS ssl_xfer_buffer,
 		  MIN(ssl_xfer_buffer_size, lim));
 error = SSL_get_error(server_ssl, inbytes);
-if (smtp_receive_timeout > 0) alarm(0);
+if (smtp_receive_timeout > 0) ALARM_CLR(0);
 
 if (had_command_timeout)		/* set by signal handler */
   smtp_command_timeout_exit();		/* does not return */
@@ -2995,9 +2995,9 @@ if (shutdown)
   if (  (rc = SSL_shutdown(*sslp)) == 0	/* send "close notify" alert */
      && shutdown > 1)
     {
-    alarm(2);
+    ALARM(2);
     rc = SSL_shutdown(*sslp);		/* wait for response */
-    alarm(0);
+    ALARM_CLR(0);
     }
 
   if (rc < 0) DEBUG(D_tls)
diff --git a/src/src/transport.c b/src/src/transport.c
index 5c72e2e2b..48c18abc6 100644
--- a/src/src/transport.c
+++ b/src/src/transport.c
@@ -256,7 +256,7 @@ for (i = 0; i < 100; i++)
 
   else
     {
-    alarm(local_timeout);
+    ALARM(local_timeout);
 
     rc =
 #ifdef SUPPORT_TLS
@@ -269,7 +269,7 @@ for (i = 0; i < 100; i++)
 	write(fd, block, len);
 
     save_errno = errno;
-    local_timeout = alarm(0);
+    local_timeout = ALARM_CLR(0);
     if (sigalrm_seen)
       {
       errno = ETIMEDOUT;
@@ -1300,9 +1300,9 @@ chunk_ptr = deliver_out_buffer;
 for (;;)
   {
   sigalrm_seen = FALSE;
-  alarm(transport_filter_timeout);
+  ALARM(transport_filter_timeout);
   len = read(fd_read, deliver_in_buffer, DELIVER_IN_BUFFER_SIZE);
-  alarm(0);
+  ALARM_CLR(0);
   if (sigalrm_seen)
     {
     errno = ETIMEDOUT;
diff --git a/src/src/transports/appendfile.c b/src/src/transports/appendfile.c
index b762b66a2..522115d44 100644
--- a/src/src/transports/appendfile.c
+++ b/src/src/transports/appendfile.c
@@ -884,10 +884,10 @@ if (dofcntl)
   {
   if (fcntltime > 0)
     {
-    alarm(fcntltime);
+    ALARM(fcntltime);
     yield = fcntl(fd, F_SETLKW, &lock_data);
     save_errno = errno;
-    alarm(0);
+    ALARM_CLR(0);
     errno = save_errno;
     }
   else yield = fcntl(fd, F_SETLK, &lock_data);
@@ -899,10 +899,10 @@ if (doflock && (yield >= 0))
   int flocktype = (fcntltype == F_WRLCK) ? LOCK_EX : LOCK_SH;
   if (flocktime > 0)
     {
-    alarm(flocktime);
+    ALARM(flocktime);
     yield = flock(fd, flocktype);
     save_errno = errno;
-    alarm(0);
+    ALARM_CLR(0);
     errno = save_errno;
     }
   else yield = flock(fd, flocktype | LOCK_NB);
diff --git a/src/src/transports/lmtp.c b/src/src/transports/lmtp.c
index 89c41d3db..cea28c943 100644
--- a/src/src/transports/lmtp.c
+++ b/src/src/transports/lmtp.c
@@ -299,10 +299,10 @@ for (;;)
 
     *readptr = 0;           /* In case nothing gets read */
     sigalrm_seen = FALSE;
-    alarm(timeout);
+    ALARM(timeout);
     rc = Ufgets(readptr, size-1, f);
     save_errno = errno;
-    alarm(0);
+    ALARM_CLR(0);
     errno = save_errno;
 
     if (rc != NULL) break;  /* A line has been read */
diff --git a/test/scripts/0000-Basic/0276 b/test/scripts/0000-Basic/0276
index 467c11e49..2e7acac4f 100644
--- a/test/scripts/0000-Basic/0276
+++ b/test/scripts/0000-Basic/0276
@@ -32,5 +32,5 @@ DATA
 QUIT
 200 OK
 ****
-exim -v -odi userx@test.ex
+exim -v -odi usery@test.ex
 ****