addr2->transport_return = addr->transport_return;
addr2->basic_errno = addr->basic_errno;
addr2->more_errno = addr->more_errno;
+ addr2->delivery_usec = addr->delivery_usec;
addr2->special_action = addr->special_action;
addr2->message = addr->message;
addr2->user_message = addr->user_message;
}
+
+void
+timesince(struct timeval * diff, struct timeval * then)
+{
+gettimeofday(diff, NULL);
+diff->tv_sec -= then->tv_sec;
+if ((diff->tv_usec -= then->tv_usec) < 0)
+ {
+ diff->tv_sec--;
+ diff->tv_usec += 1000*1000;
+ }
+}
+
+
+
+static uschar *
+string_timediff(struct timeval * diff)
+{
+static uschar buf[sizeof("0.000s")];
+
+if (diff->tv_sec >= 5 || !LOGGING(millisec))
+ return readconf_printtime((int)diff->tv_sec);
+
+sprintf(CS buf, "%d.%03ds", (int)diff->tv_sec, (int)diff->tv_usec/1000);
+return buf;
+}
+
+
+static uschar *
+string_timesince(struct timeval * then)
+{
+struct timeval diff;
+
+timesince(&diff, then);
+return string_timediff(&diff);
+}
+
/******************************************************************************/
if (LOGGING(queue_time))
s = string_append(s, &size, &ptr, 2, US" QT=",
- readconf_printtime( (int) ((long)time(NULL) - (long)received_time)) );
+ string_timesince(&received_time));
if (LOGGING(deliver_time))
- s = string_append(s, &size, &ptr, 2, US" DT=",
- readconf_printtime(addr->more_errno));
+ {
+ struct timeval diff = {addr->more_errno, addr->delivery_usec};
+ s = string_append(s, &size, &ptr, 2, US" DT=", string_timediff(&diff));
+ }
/* string_cat() always leaves room for the terminator. Release the
store we used to build the line after writing it. */
|| (ret = write(pfd[pipe_write], &addr2->flags, sizeof(addr2->flags))) != sizeof(addr2->flags)
|| (ret = write(pfd[pipe_write], &addr2->basic_errno, sizeof(int))) != sizeof(int)
|| (ret = write(pfd[pipe_write], &addr2->more_errno, sizeof(int))) != sizeof(int)
+ || (ret = write(pfd[pipe_write], &addr2->delivery_usec, sizeof(int))) != sizeof(int)
|| (ret = write(pfd[pipe_write], &addr2->special_action, sizeof(int))) != sizeof(int)
|| (ret = write(pfd[pipe_write], &addr2->transport,
sizeof(transport_instance *))) != sizeof(transport_instance *)
len = read(pfd[pipe_read], &addr2->flags, sizeof(addr2->flags));
len = read(pfd[pipe_read], &addr2->basic_errno, sizeof(int));
len = read(pfd[pipe_read], &addr2->more_errno, sizeof(int));
+ len = read(pfd[pipe_read], &addr2->delivery_usec, sizeof(int));
len = read(pfd[pipe_read], &addr2->special_action, sizeof(int));
len = read(pfd[pipe_read], &addr2->transport,
sizeof(transport_instance *));
while (addr_local)
{
- time_t delivery_start;
- int deliver_time;
+ struct timeval delivery_start;
+ struct timeval deliver_time;
address_item *addr2, *addr3, *nextaddr;
int logflags = LOG_MAIN;
int logchar = dont_deliver? '*' : '=';
single delivery. */
deliver_set_expansions(addr);
- delivery_start = time(NULL);
+
+ gettimeofday(&delivery_start, NULL);
deliver_local(addr, FALSE);
- deliver_time = (int)(time(NULL) - delivery_start);
+ timesince(&deliver_time, &delivery_start);
/* If a shadow transport (which must perforce be another local transport), is
defined, and its condition is met, we must pass the message to the shadow
/* Done with this address */
- if (result == OK) addr2->more_errno = deliver_time;
+ if (result == OK)
+ {
+ addr2->more_errno = deliver_time.tv_sec;
+ addr2->delivery_usec = deliver_time.tv_usec;
+ }
post_process_one(addr2, result, logflags, DTYPE_TRANSPORT, logchar);
/* If a pipe delivery generated text to be sent back, the result may be
r->flags = *ptr++;
r->key = string_copy(ptr);
while (*ptr++);
- memcpy(&(r->basic_errno), ptr, sizeof(r->basic_errno));
+ memcpy(&r->basic_errno, ptr, sizeof(r->basic_errno));
ptr += sizeof(r->basic_errno);
- memcpy(&(r->more_errno), ptr, sizeof(r->more_errno));
+ memcpy(&r->more_errno, ptr, sizeof(r->more_errno));
ptr += sizeof(r->more_errno);
r->message = *ptr ? string_copy(ptr) : NULL;
DEBUG(D_deliver|D_retry) debug_printf(" added %s item\n",
DEBUG(D_deliver) debug_printf("A0 %s tret %d\n", addr->address, *ptr);
addr->transport_return = *ptr++;
addr->special_action = *ptr++;
- memcpy(&(addr->basic_errno), ptr, sizeof(addr->basic_errno));
+ memcpy(&addr->basic_errno, ptr, sizeof(addr->basic_errno));
ptr += sizeof(addr->basic_errno);
- memcpy(&(addr->more_errno), ptr, sizeof(addr->more_errno));
+ memcpy(&addr->more_errno, ptr, sizeof(addr->more_errno));
ptr += sizeof(addr->more_errno);
- memcpy(&(addr->flags), ptr, sizeof(addr->flags));
+ memcpy(&addr->delivery_usec, ptr, sizeof(addr->delivery_usec));
+ ptr += sizeof(addr->delivery_usec);
+ memcpy(&addr->flags, ptr, sizeof(addr->flags));
ptr += sizeof(addr->flags);
addr->message = *ptr ? string_copy(ptr) : NULL;
while(*ptr++);
{
sprintf(CS big_buffer, "%c%.500s", r->flags, r->key);
ptr = big_buffer + Ustrlen(big_buffer+2) + 3;
- memcpy(ptr, &(r->basic_errno), sizeof(r->basic_errno));
+ memcpy(ptr, &r->basic_errno, sizeof(r->basic_errno));
ptr += sizeof(r->basic_errno);
- memcpy(ptr, &(r->more_errno), sizeof(r->more_errno));
+ memcpy(ptr, &r->more_errno, sizeof(r->more_errno));
ptr += sizeof(r->more_errno);
if (!r->message) *ptr++ = 0; else
{
sprintf(CS big_buffer, "%c%c", addr->transport_return, addr->special_action);
ptr = big_buffer + 2;
- memcpy(ptr, &(addr->basic_errno), sizeof(addr->basic_errno));
+ memcpy(ptr, &addr->basic_errno, sizeof(addr->basic_errno));
ptr += sizeof(addr->basic_errno);
- memcpy(ptr, &(addr->more_errno), sizeof(addr->more_errno));
+ memcpy(ptr, &addr->more_errno, sizeof(addr->more_errno));
ptr += sizeof(addr->more_errno);
- memcpy(ptr, &(addr->flags), sizeof(addr->flags));
+ memcpy(ptr, &addr->delivery_usec, sizeof(addr->delivery_usec));
+ ptr += sizeof(addr->delivery_usec);
+ memcpy(ptr, &addr->flags, sizeof(addr->flags));
ptr += sizeof(addr->flags);
if (!addr->message) *ptr++ = 0; else
{
ptr += sprintf(CS ptr, "%.256s", addr->host_used->name) + 1;
ptr += sprintf(CS ptr, "%.64s", addr->host_used->address) + 1;
- memcpy(ptr, &(addr->host_used->port), sizeof(addr->host_used->port));
+ memcpy(ptr, &addr->host_used->port, sizeof(addr->host_used->port));
ptr += sizeof(addr->host_used->port);
/* DNS lookup status */
if (rc != spool_read_hdrerror)
{
- received_time = 0;
+ received_time.tv_sec = received_time.tv_usec = 0;
+ /*XXX subsec precision?*/
for (i = 0; i < 6; i++)
- received_time = received_time * BASE_62 + tab62[id[i] - '0'];
+ received_time.tv_sec = received_time.tv_sec * BASE_62 + tab62[id[i] - '0'];
}
/* If we've had this malformed message too long, sling it. */
- if (now - received_time > keep_malformed)
+ if (now - received_time.tv_sec > keep_malformed)
{
Uunlink(spool_fname(US"msglog", message_subdir, id, US""));
Uunlink(spool_fname(US"input", message_subdir, id, US"-D"));
if (rc != 0)
{
uschar *s = US"";
- if (now - received_time < retry_maximum_timeout && !addr_defer)
+ if (now - received_time.tv_sec < retry_maximum_timeout && !addr_defer)
{
addr_defer = (address_item *)(+1);
deliver_freeze = TRUE;
if (LOGGING(queue_time_overall))
log_write(0, LOG_MAIN, "Completed QT=%s",
- readconf_printtime( (int) ((long)time(NULL) - (long)received_time)) );
+ string_timesince(&received_time));
else
log_write(0, LOG_MAIN, "Completed");
{
int count;
int show_time;
- int queue_time = time(NULL) - received_time;
+ int queue_time = time(NULL) - received_time.tv_sec;
/* When running in the test harness, there's an option that allows us to
fudge this time so as to get repeatability of the tests. Take the first