From 6703712bff65f728d568e9322ee2c83a70446b5d Mon Sep 17 00:00:00 2001
From: Kevin Atkinson <kevina@cs.utah.edu>
Date: Thu, 7 Dec 2006 19:47:28 +0000
Subject: [PATCH] Change timestamp output of event-sched to something human
readable.
Also add a small amount of debug output to "$ns report" to help me
track down why it is being called at seemingly random places.
---
event/lib/event.h | 1 +
event/lib/util.c | 18 ++++++++++++++++++
event/sched/event-sched.c | 21 +++++++++++++--------
event/sched/event-sched.h | 1 +
event/sched/simulator-agent.cc | 11 +++++++++++
5 files changed, 44 insertions(+), 8 deletions(-)
diff --git a/event/lib/event.h b/event/lib/event.h
index cad81dc8b1..4b92b6975c 100644
--- a/event/lib/event.h
+++ b/event/lib/event.h
@@ -283,6 +283,7 @@ int event_do(event_handle_t handle, ea_tag_t tag, ...);
/* util.c */
void *xmalloc(int size);
void *xrealloc(void *p, int size);
+void make_timestamp(char * buf, const struct timeval * t_timeval);
#ifdef __cplusplus
}
diff --git a/event/lib/util.c b/event/lib/util.c
index 3151a4dae2..fe91de8c2c 100644
--- a/event/lib/util.c
+++ b/event/lib/util.c
@@ -13,6 +13,7 @@
#include <stdio.h>
#include <stdlib.h>
+#include <time.h>
#include "event.h"
/* Attempt to allocate SIZE bytes of memory and exit if memory
@@ -43,3 +44,20 @@ xrealloc(void *p, int size)
}
return q;
}
+
+/* Format a timeval into a nice timestamp
+ * Buffer must be 24 bytes wide (including null character)
+ */
+void
+make_timestamp(char * buf, const struct timeval * t_timeval)
+{
+ struct tm t_tm;
+ time_t secs = t_timeval->tv_sec;
+ localtime_r(&secs, &t_tm);
+ strftime(buf, 17, "%Y%m%d_%T", &t_tm);
+ snprintf(buf+17, 5, ".%03ld", t_timeval->tv_usec/1000);
+}
+
+
+
+
diff --git a/event/sched/event-sched.c b/event/sched/event-sched.c
index 4c00886a86..c7edc3be5d 100644
--- a/event/sched/event-sched.c
+++ b/event/sched/event-sched.c
@@ -798,15 +798,19 @@ enqueue(event_handle_t handle, event_notification_t notification, void *data)
}
if (debug) {
+ char time_buf_1[24], time_buf_2[24];
struct timeval now;
gettimeofday(&now, NULL);
+
+ make_timestamp(time_buf_1, &event.time);
+ make_timestamp(time_buf_2, &now);
info("Sched: "
- "note:%p at:%ld:%d now:%ld:%d agent:%s %s\n",
+ "note:%p at:%s now:%s agent:%s %s\n",
event.notification,
- event.time.tv_sec, event.time.tv_usec,
- now.tv_sec, now.tv_usec, agentp->name,
+ time_buf_1, time_buf_2,
+ agentp->name,
eventtype);
}
@@ -897,7 +901,8 @@ dequeue(event_handle_t handle)
{
sched_event_t next_event;
struct timeval now;
-
+ char time_buf_1[24], time_buf_2[24];
+
while (1) {
if (sched_event_dequeue(&next_event, 1) < 0)
break;
@@ -907,11 +912,11 @@ dequeue(event_handle_t handle)
gettimeofday(&now, NULL);
if (debug) {
- info("Fire: note:%p at:%ld:%d now:%ld:%d agent:%s\n",
+ make_timestamp(time_buf_1, &next_event.time);
+ make_timestamp(time_buf_2, &now);
+ info("Fire: note:%p at:%s now:%s agent:%s\n",
next_event.notification,
- next_event.time.tv_sec, next_event.time.tv_usec,
- now.tv_sec,
- now.tv_usec,
+ time_buf_1, time_buf_2,
next_event.agent.s ?
(next_event.length == 1 ?
next_event.agent.s->name :
diff --git a/event/sched/event-sched.h b/event/sched/event-sched.h
index 1844f39775..c29e31e5c8 100644
--- a/event/sched/event-sched.h
+++ b/event/sched/event-sched.h
@@ -93,6 +93,7 @@ int sched_event_prepare(event_handle_t handle, sched_event_t *se);
int sched_event_enqueue_copy(event_handle_t handle,
sched_event_t *se,
struct timeval *new_time);
+void make_timestamp(char * buf, const struct timeval * t_timeval);
/* queue.c */
void sched_event_init(void);
diff --git a/event/sched/simulator-agent.cc b/event/sched/simulator-agent.cc
index ae6461ede9..f8401a0de1 100644
--- a/event/sched/simulator-agent.cc
+++ b/event/sched/simulator-agent.cc
@@ -17,6 +17,7 @@
#include "popenf.h"
#include "systemf.h"
#include "rpc.h"
+#include "log.h"
#include "simulator-agent.h"
using namespace emulab;
@@ -232,6 +233,16 @@ int send_report(simulator_agent_t sa, char *args)
assert(lnEmptyList(&sa->sa_error_records));
if (pthread_mutex_unlock(&sa->sa_local_agent.la_mutex) != 0)
assert(0);
+
+ if (debug) {
+ char time_buf[24];
+ struct timeval now;
+ gettimeofday(&now, NULL);
+ make_timestamp(time_buf, &now);
+ info("Sending Report at %s with args \"%s\"\n",
+ time_buf, args);
+ }
+
/*
* Get the logs off the nodes so we can generate summaries from the
--
GitLab