Fix bug in overlay_gettime_ms()

The sequence start time was only getting set in overlay_interface_init(), which
was not always called, or was called after overlay_gettime_ms() had already
been used.

Added FATALF(), FATAL() and FATAL_perror() macros.

Removed a bunch of debug statements no longer needed in monitor.c and server.c.

commandline.c

@@ -615,13 +615,13 @@ int app_server_start(int argc, const char *const *argv, struct command_line_opti
     /* Parent process.  Wait for the child process to fork the grandchild then die. */
     waitpid(cpid, NULL, 0);
     /* Allow a few seconds for the grandchild process to report for duty. */
-    time_t timeout = overlay_gettime_ms() + 5000;
+    long long timeout = gettime_ms() + 5000;
     do {
       struct timespec delay;
       delay.tv_sec = 0;
       delay.tv_nsec = 200000000; // 200 ms = 5 Hz
       nanosleep(&delay, NULL);
-    } while ((pid = server_pid()) == 0 && overlay_gettime_ms() < timeout);
+    } while ((pid = server_pid()) == 0 && gettime_ms() < timeout);
     if (pid == -1)
       return -1;
     if (pid == 0)
@@ -680,13 +680,13 @@ int app_server_stop(int argc, const char *const *argv, struct command_line_optio
       return WHYF("Error sending SIGHUP to Servald pid=%d for instance '%s'", pid, instancepath);
     }
     /* Allow a few seconds for the process to die. */
-    time_t timeout = overlay_gettime_ms() + 2000;
+    long long timeout = gettime_ms() + 2000;
     do {
       struct timespec delay;
       delay.tv_sec = 0;
       delay.tv_nsec = 200000000; // 200 ms = 5 Hz
       nanosleep(&delay, NULL);
-    } while ((running = server_pid()) == pid && overlay_gettime_ms() < timeout);
+    } while ((running = server_pid()) == pid && gettime_ms() < timeout);
   }
   server_remove_stopfile();
   cli_puts("tries");
@@ -1001,7 +1001,7 @@ int app_rhizome_add_file(int argc, const char *const *argv, struct command_line_
     rhizome_manifest_set(m, "name", name);
   }
   if (rhizome_manifest_get(m, "date", NULL, 0) == NULL) {
-    rhizome_manifest_set_ll(m, "date", overlay_gettime_ms());
+    rhizome_manifest_set_ll(m, "date", gettime_ms());
   }
   /* Add the manifest and its associated file to the Rhizome database, generating an "id" in the
    * process */

monitor.c

@@ -89,7 +89,6 @@ int monitor_setup_sockets()
       int dud=0;
       int r=bind(monitor_named_socket, (struct sockaddr *)&name, len);
       if (r) { dud=1; r=0; WHY_perror("bind"); }
-      DEBUG("listen"); //XXX
       r=listen(monitor_named_socket,MAX_MONITOR_SOCKETS);
       if (r) { dud=1; r=0; WHY_perror("listen");
       }
@@ -185,10 +184,8 @@ int monitor_poll()
 	fcntl(monitor_named_socket, F_GETFL, NULL)|O_NONBLOCK);
   while (
 #ifdef HAVE_LINUX_IF_H
-	 (DEBUG("accept4"), 1) && //XXX
 	 (s = accept4(monitor_named_socket,ignored_address,&ignored_length,O_NONBLOCK))
 #else
-	 (DEBUG("accept"), 1) && //XXX
 	 (s = accept(monitor_named_socket,ignored_address,&ignored_length))
 #endif
       != -1
@@ -253,7 +250,6 @@ int monitor_poll()
 	  break;
 	}
 	errno=0;
-	DEBUG("read"); //XXX
 	bytes=read(c->socket,&c->line[c->line_length],1);
 	if (bytes<1) {
 	  switch(errno) {
@@ -296,7 +292,6 @@ int monitor_poll()
       break;
     case MONITOR_STATE_DATA:
       errno=0;
-      DEBUG("read"); //XXX
       bytes=read(c->socket,
 		 &c->buffer[c->data_offset],
 		 c->data_expected-c->data_offset);

overlay.c

@@ -170,24 +170,21 @@ int overlayServerMode()
     if (ms>vomp_tick_time) ms=vomp_tick_time;
 
     if (debug&DEBUG_VERBOSE_IO)
-      fprintf(stderr,"Waiting via poll() for up to %lldms\n",ms);
-    int r=poll(fds,fdcount,ms);
-    if (debug&DEBUG_VERBOSE_IO) {
-      fprintf(stderr,"poll() says %d file descriptors are ready\n",r);
+      DEBUGF("Waiting via poll() for up to %lldms", ms);
+    int r = poll(fds, fdcount, ms);
+    if (r == -1)
+      WHY_perror("poll");
+    else if (debug&DEBUG_VERBOSE_IO) {
+      DEBUGF("poll() says %d file descriptors are ready", r);
       int i;
       for(i=0;i<fdcount;i++)
-	if (fds[i].revents) 
-	  fprintf(stderr,"fd #%d is ready (0x%x)\n",
-		  fds[i].fd,fds[i].revents);
-    }   
-
+	if (fds[i].revents)
+	  DEBUGF("fd #%d is ready (0x%x)\n", fds[i].fd, fds[i].revents);
+    }
     /* Do high-priority audio handling first */
     vomp_tick();
 
-    if (r<0) {
-      /* select had a problem */
-      WHY_perror("poll");
-    } else if (r>0) {
+    if (r > 0) {
       /* We have data, so try to receive it */
       if (debug&DEBUG_IO) {
 	fprintf(stderr,"poll() reports %d fds ready\n",r);

overlay_interface.c

@@ -41,21 +41,19 @@ struct interface_rules {
 struct interface_rules *interface_filter=NULL;
 
 unsigned int overlay_sequence_number=0;
-time_t overlay_sequence_start_time;
 
 /* Do we need to repeat our abbreviation policy? */
 int overlay_interface_repeat_abbreviation_policy[OVERLAY_MAX_INTERFACES]={1};
 
+/* Return milliseconds since server started.  First call will always return zero.  */
 long long overlay_gettime_ms()
 {
-  struct timeval nowtv;
-  if (gettimeofday(&nowtv,NULL))
-    return WHY("gettimeofday() failed");
-
-  /* Get current time in milliseconds */
-  long long now=(nowtv.tv_sec-overlay_sequence_start_time)*1000LL;
-  now=now+nowtv.tv_usec/1000;
-
+  static time_t overlay_sequence_start_time = 0;
+  long long now = gettime_ms();
+  if (!overlay_sequence_start_time) {
+    overlay_sequence_start_time = now;
+    now = 0;
+  }
   return now;
 }
 
@@ -250,8 +248,6 @@ int overlay_interface_init(char *name,struct sockaddr_in src_addr,struct sockadd
   case OVERLAY_INTERFACE_WIFI: I(tick_ms)=500; break;
   }
 
-  if (!overlay_sequence_start_time) overlay_sequence_start_time=time(0);
-
   if (name[0]=='>') {
     I(fileP)=1;
     char dummyfile[1024];

rhizome.c

@@ -228,7 +228,7 @@ int rhizome_add_manifest(rhizome_manifest *m_in,
 
   /* Supply manifest version number if missing, so we can do the version check below */
   if (m_in->version == -1) {
-    m_in->version = overlay_gettime_ms();
+    m_in->version = gettime_ms();
     rhizome_manifest_set_ll(m_in, "version", m_in->version);
   }
 

rhizome_bundle.c

@@ -485,7 +485,7 @@ int rhizome_manifest_finalise(rhizome_manifest *m,int signP)
   if (rhizome_manifest_get(m,"version",NULL,0)==NULL)
     {
       /* No version set */
-      m->version = overlay_gettime_ms();
+      m->version = gettime_ms();
       rhizome_manifest_set_ll(m,"version",m->version);
     }
   else

rhizome_database.c

@@ -343,7 +343,7 @@ int rhizome_store_bundle(rhizome_manifest *m, const char *associated_filename)
   if (debug & DEBUG_RHIZOME) fprintf(stderr, "Writing into manifests table\n");
   snprintf(sqlcmd,1024,
 	   "INSERT INTO MANIFESTS(id,manifest,version,inserttime,bar) VALUES('%s',?,%lld,%lld,?);",
-	   manifestid,m->version,overlay_gettime_ms());
+	   manifestid, m->version, gettime_ms());
 
   if (m->haveSecret) {
     if (rhizome_store_keypair_bytes(m->cryptoSignPublic,m->cryptoSignSecret))

serval.h

@@ -398,6 +398,7 @@ int respondSimple(keyring_identity *id,
 int requestItem(char *did,char *sid,char *item,int instance,unsigned char *buffer,int buffer_length,int *len,
 		unsigned char *transaction_id);
 int requestNewHLR(char *did,char *pin,char *sid,int recvttl,struct sockaddr *recvaddr);
+long long gettime_ms();
 int server_pid();
 void server_save_argv(int argc, const char *const *argv);
 int server(char *backing_file);
@@ -631,7 +632,6 @@ typedef struct overlay_interface {
 extern overlay_interface overlay_interfaces[OVERLAY_MAX_INTERFACES];
 extern int overlay_last_interface_number; // used to remember where a packet came from
 extern unsigned int overlay_sequence_number;
-extern time_t overlay_sequence_start_time;
 
 /* Has someone sent us an abbreviation of an unknown type recently? If so remind them
    that we don't accept these.
@@ -748,14 +748,18 @@ int setReason(char *fmt, ...);
 void logMessage(int level, char *fmt, ...);
 void vlogMessage(int level, char *fmt, va_list);
 
+#define FATALF(F,...)       do { logMessage(LOG_LEVEL_FATAL, "%s:%d:%s()  " F, __FILE__, __LINE__, __FUNCTION__, ##__VA_ARGS__); exit(-1); } while(1)
+#define FATAL(X)            FATALF("%s", (X))
+#define FATAL_perror(X)     FATALF("%s: %s [errno=%d]", (X), strerror(errno), errno)
+
 #define WHY(X) setReason("%s:%d:%s()  %s",__FILE__,__LINE__,__FUNCTION__,X)
 #define WHYNULL(X) (setReason("%s:%d:%s()  %s",__FILE__,__LINE__,__FUNCTION__,X), NULL)
 #define WHYF(F,...) setReason("%s:%d:%s()  " F, __FILE__, __LINE__, __FUNCTION__, ##__VA_ARGS__)
 #define WHY_perror(X) setReason("%s:%d:%s()  %s: %s [errno=%d]", __FILE__, __LINE__, __FUNCTION__, X, strerror(errno), errno)
 
 #define DEBUGF(F,...) logMessage(LOG_LEVEL_DEBUG, "%s:%d:%s()  " F, __FILE__, __LINE__, __FUNCTION__, ##__VA_ARGS__)
-#define DEBUG(X) DEBUGF("%s", X)
-#define DEBUG_perror(X) DEBUGF("%s: %s [errno=%d]", X, strerror(errno), errno)
+#define DEBUG(X) DEBUGF("%s", (X))
+#define DEBUG_perror(X) DEBUGF("%s: %s [errno=%d]", (X), strerror(errno), errno)
 #define D DEBUG("D")
 
 overlay_buffer *ob_new(int size);

server.c

@@ -109,6 +109,14 @@ int recvwithttl(int sock,unsigned char *buffer,int bufferlen,int *ttl,
   return len;
 }
 
+long long gettime_ms()
+{
+  struct timeval nowtv;
+  if (gettimeofday(&nowtv, NULL))
+    FATAL_perror("gettimeofday"); // If this fails, all else is lost!
+  return nowtv.tv_sec * 1000LL + nowtv.tv_usec / 1000;
+}
+
 /** Return the PID of the currently running server process, return 0 if there is none.
  */
 int server_pid()
@@ -220,9 +228,8 @@ void server_shutdown_check()
       file will change or be unaccessible.  In this case, shut down without all the cleanup.
       Perform this check at most once per second.  */
   static long long server_pid_time_ms = 0;
-  long long time_ms = overlay_gettime_ms();
+  long long time_ms = gettime_ms();
   if (server_pid_time_ms == 0 || time_ms - server_pid_time_ms > 1000) {
-    WHYF("time_ms=%lld", time_ms);
     server_pid_time_ms = time_ms;
     if (server_pid() != server_getpid) {
       WHYF("Server pid file no longer contains pid=%d -- shutting down without cleanup", server_getpid);