diff --git a/event/lib/event.h b/event/lib/event.h index cad81dc8b1a645a4f15ad4012ac27a78d08c5adb..4b92b6975cea39d8def19deed7145403268b9e16 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 3151a4dae26a5a34f28e958139cb6c6bb38ae552..fe91de8c2cfc13ffd30f0cd659c588a5a3add355 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 4c00886a8653b6ac00500ca761dee8c4db621b87..c7edc3be5d0d81b86954087fd0a9a3c952ccb9ac 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 1844f3977576333fbe44f81fdedd8696376cec7e..c29e31e5c895a960f63703bd2502961809301eff 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 ae6461ede901d2ef859033ba64dcaed1d1d161cc..f8401a0de16cddbca07a500645912d3e4d17543a 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