Addresses #1792 refs[t:1792] Added timestamps to engine status

git-svn-id: file:///svn/toku/tokudb@14817 c7de825b-a66e-492c-adef-691d508d4ae1

buildheader/db.h_4_1

@@ -43,9 +43,13 @@ typedef struct __toku_db_btree_stat64 {
   u_int64_t bt_fsize; /* how big is the underlying file                                                         */
 } DB_BTREE_STAT64;
 typedef struct __toku_engine_status {
+  char             now[26];                 /* time of engine status query (i.e. now)  */ 
   u_int32_t        ydb_lock_ctr;            /* how many times has ydb lock been taken/released */ 
   u_int32_t        checkpoint_period;       /* delay between automatic checkpoints  */ 
   u_int32_t        checkpoint_footprint;    /* state of checkpoint procedure        */ 
+  char             checkpoint_time_begin[26]; /* time of last checkpoint begin      */ 
+  char             checkpoint_time_begin_complete[26]; /* time of last complete checkpoint begin      */ 
+  char             checkpoint_time_end[26]; /* time of last checkpoint end      */ 
   u_int32_t        cachetable_lock_ctr;     /* how many times has cachetable lock been taken/released */ 
   u_int64_t        cachetable_hit;          /* how many cache hits   */ 
   u_int64_t        cachetable_miss;         /* how many cache misses */ 

buildheader/db.h_4_3

@@ -43,9 +43,13 @@ typedef struct __toku_db_btree_stat64 {
   u_int64_t bt_fsize; /* how big is the underlying file                                                         */
 } DB_BTREE_STAT64;
 typedef struct __toku_engine_status {
+  char             now[26];                 /* time of engine status query (i.e. now)  */ 
   u_int32_t        ydb_lock_ctr;            /* how many times has ydb lock been taken/released */ 
   u_int32_t        checkpoint_period;       /* delay between automatic checkpoints  */ 
   u_int32_t        checkpoint_footprint;    /* state of checkpoint procedure        */ 
+  char             checkpoint_time_begin[26]; /* time of last checkpoint begin      */ 
+  char             checkpoint_time_begin_complete[26]; /* time of last complete checkpoint begin      */ 
+  char             checkpoint_time_end[26]; /* time of last checkpoint end      */ 
   u_int32_t        cachetable_lock_ctr;     /* how many times has cachetable lock been taken/released */ 
   u_int64_t        cachetable_hit;          /* how many cache hits   */ 
   u_int64_t        cachetable_miss;         /* how many cache misses */ 

buildheader/db.h_4_4

@@ -43,9 +43,13 @@ typedef struct __toku_db_btree_stat64 {
   u_int64_t bt_fsize; /* how big is the underlying file                                                         */
 } DB_BTREE_STAT64;
 typedef struct __toku_engine_status {
+  char             now[26];                 /* time of engine status query (i.e. now)  */ 
   u_int32_t        ydb_lock_ctr;            /* how many times has ydb lock been taken/released */ 
   u_int32_t        checkpoint_period;       /* delay between automatic checkpoints  */ 
   u_int32_t        checkpoint_footprint;    /* state of checkpoint procedure        */ 
+  char             checkpoint_time_begin[26]; /* time of last checkpoint begin      */ 
+  char             checkpoint_time_begin_complete[26]; /* time of last complete checkpoint begin      */ 
+  char             checkpoint_time_end[26]; /* time of last checkpoint end      */ 
   u_int32_t        cachetable_lock_ctr;     /* how many times has cachetable lock been taken/released */ 
   u_int64_t        cachetable_hit;          /* how many cache hits   */ 
   u_int64_t        cachetable_miss;         /* how many cache misses */ 

buildheader/db.h_4_5

@@ -43,9 +43,13 @@ typedef struct __toku_db_btree_stat64 {
   u_int64_t bt_fsize; /* how big is the underlying file                                                         */
 } DB_BTREE_STAT64;
 typedef struct __toku_engine_status {
+  char             now[26];                 /* time of engine status query (i.e. now)  */ 
   u_int32_t        ydb_lock_ctr;            /* how many times has ydb lock been taken/released */ 
   u_int32_t        checkpoint_period;       /* delay between automatic checkpoints  */ 
   u_int32_t        checkpoint_footprint;    /* state of checkpoint procedure        */ 
+  char             checkpoint_time_begin[26]; /* time of last checkpoint begin      */ 
+  char             checkpoint_time_begin_complete[26]; /* time of last complete checkpoint begin      */ 
+  char             checkpoint_time_end[26]; /* time of last checkpoint end      */ 
   u_int32_t        cachetable_lock_ctr;     /* how many times has cachetable lock been taken/released */ 
   u_int64_t        cachetable_hit;          /* how many cache hits   */ 
   u_int64_t        cachetable_miss;         /* how many cache misses */ 

buildheader/db.h_4_6

@@ -43,9 +43,13 @@ typedef struct __toku_db_btree_stat64 {
   u_int64_t bt_fsize; /* how big is the underlying file                                                         */
 } DB_BTREE_STAT64;
 typedef struct __toku_engine_status {
+  char             now[26];                 /* time of engine status query (i.e. now)  */ 
   u_int32_t        ydb_lock_ctr;            /* how many times has ydb lock been taken/released */ 
   u_int32_t        checkpoint_period;       /* delay between automatic checkpoints  */ 
   u_int32_t        checkpoint_footprint;    /* state of checkpoint procedure        */ 
+  char             checkpoint_time_begin[26]; /* time of last checkpoint begin      */ 
+  char             checkpoint_time_begin_complete[26]; /* time of last complete checkpoint begin      */ 
+  char             checkpoint_time_end[26]; /* time of last checkpoint end      */ 
   u_int32_t        cachetable_lock_ctr;     /* how many times has cachetable lock been taken/released */ 
   u_int64_t        cachetable_hit;          /* how many cache hits   */ 
   u_int64_t        cachetable_miss;         /* how many cache misses */ 

buildheader/make_db_h.c

@@ -347,9 +347,13 @@ int main (int argc __attribute__((__unused__)), char *argv[] __attribute__((__un
 
     //engine status info
     printf("typedef struct __toku_engine_status {\n");
+    printf("  char             now[26];                 /* time of engine status query (i.e. now)  */ \n");
     printf("  u_int32_t        ydb_lock_ctr;            /* how many times has ydb lock been taken/released */ \n");
     printf("  u_int32_t        checkpoint_period;       /* delay between automatic checkpoints  */ \n");
     printf("  u_int32_t        checkpoint_footprint;    /* state of checkpoint procedure        */ \n");
+    printf("  char             checkpoint_time_begin[26]; /* time of last checkpoint begin      */ \n");
+    printf("  char             checkpoint_time_begin_complete[26]; /* time of last complete checkpoint begin      */ \n");
+    printf("  char             checkpoint_time_end[26]; /* time of last checkpoint end      */ \n");
     printf("  u_int32_t        cachetable_lock_ctr;     /* how many times has cachetable lock been taken/released */ \n");
     printf("  u_int64_t        cachetable_hit;          /* how many cache hits   */ \n");
     printf("  u_int64_t        cachetable_miss;         /* how many cache misses */ \n");
@@ -371,6 +375,7 @@ int main (int argc __attribute__((__unused__)), char *argv[] __attribute__((__un
     printf("  u_int64_t        aborts;                  /* ydb txn abort operations             */ \n");
     printf("  u_int64_t        point_queries;           /* ydb point queries                    */ \n");
     printf("  u_int64_t        sequential_queries;      /* ydb sequential queries               */ \n");
+    
 
     //    printf("  struct timeval   checkpoint_tbegin;       /* time of last checkpoint begin        */ \n");
     //    printf("  struct timeval   checkpoint_tend;         /* time of last checkpoint end          */ \n");

buildheader/tdb.h

@@ -43,9 +43,13 @@ typedef struct __toku_db_btree_stat64 {
   u_int64_t bt_fsize; /* how big is the underlying file                                                         */
 } DB_BTREE_STAT64;
 typedef struct __toku_engine_status {
+  char             now[26];                 /* time of engine status query (i.e. now)  */ 
   u_int32_t        ydb_lock_ctr;            /* how many times has ydb lock been taken/released */ 
   u_int32_t        checkpoint_period;       /* delay between automatic checkpoints  */ 
   u_int32_t        checkpoint_footprint;    /* state of checkpoint procedure        */ 
+  char             checkpoint_time_begin[26]; /* time of last checkpoint begin      */ 
+  char             checkpoint_time_begin_complete[26]; /* time of last complete checkpoint begin      */ 
+  char             checkpoint_time_end[26]; /* time of last checkpoint end      */ 
   u_int32_t        cachetable_lock_ctr;     /* how many times has cachetable lock been taken/released */ 
   u_int64_t        cachetable_hit;          /* how many cache hits   */ 
   u_int64_t        cachetable_miss;         /* how many cache misses */ 

include/db.h

@@ -43,9 +43,13 @@ typedef struct __toku_db_btree_stat64 {
   u_int64_t bt_fsize; /* how big is the underlying file                                                         */
 } DB_BTREE_STAT64;
 typedef struct __toku_engine_status {
+  char             now[26];                 /* time of engine status query (i.e. now)  */ 
   u_int32_t        ydb_lock_ctr;            /* how many times has ydb lock been taken/released */ 
   u_int32_t        checkpoint_period;       /* delay between automatic checkpoints  */ 
   u_int32_t        checkpoint_footprint;    /* state of checkpoint procedure        */ 
+  char             checkpoint_time_begin[26]; /* time of last checkpoint begin      */ 
+  char             checkpoint_time_begin_complete[26]; /* time of last complete checkpoint begin      */ 
+  char             checkpoint_time_end[26]; /* time of last checkpoint end      */ 
   u_int32_t        cachetable_lock_ctr;     /* how many times has cachetable lock been taken/released */ 
   u_int64_t        cachetable_hit;          /* how many cache hits   */ 
   u_int64_t        cachetable_miss;         /* how many cache misses */ 

newbrt/checkpoint.c

@@ -37,6 +37,7 @@
  *  - ydb_big_lock
  *    This is the existing lock used to serialize all access to tokudb.
  *    This lock is held by the checkpoint function only for as long as is required to 
+
  *    to set all the "pending" bits and to create the checkpoint-in-progress versions
  *    of the header and translation table (btt).
  *    
@@ -48,14 +49,19 @@
  *****/
 
 #include <toku_portability.h>
+#include <time.h>
+
 #include "brttypes.h"
 #include "cachetable.h"
 #include "log-internal.h"
 #include "logger.h"
 #include "checkpoint.h"
 
-// footprint for debugging and status reporting only
+// for debugging/accountability and status reporting only
 static u_int32_t checkpoint_footprint = 0;
+static time_t time_last_checkpoint_begin_complete;
+static time_t time_last_checkpoint_begin;
+static time_t time_last_checkpoint_end;
 
 static toku_pthread_rwlock_t checkpoint_safe_lock;
 static toku_pthread_rwlock_t multi_operation_lock;
@@ -156,9 +162,12 @@ toku_checkpoint_safe_client_unlock(void) {
 }
 
 
-u_int32_t 
-toku_checkpoint_get_footprint(void) {
-    return checkpoint_footprint;
+void
+toku_checkpoint_get_status(CHECKPOINT_STATUS s) {
+    s->footprint = checkpoint_footprint;
+    s->time_last_checkpoint_begin_complete = time_last_checkpoint_begin_complete;
+    s->time_last_checkpoint_begin = time_last_checkpoint_begin;
+    s->time_last_checkpoint_end   = time_last_checkpoint_end;
 }
 
 
@@ -207,6 +216,7 @@ toku_checkpoint(CACHETABLE ct, TOKULOGGER logger, char **error_string,
     ydb_lock();
     
     checkpoint_footprint = 40;
+    time_last_checkpoint_begin = time(NULL);
     r = toku_cachetable_begin_checkpoint(ct, logger);
     LSN oldest_live_lsn = toku_logger_get_oldest_living_lsn(logger);
 
@@ -225,6 +235,8 @@ toku_checkpoint(CACHETABLE ct, TOKULOGGER logger, char **error_string,
     }
 
     checkpoint_footprint = 60;
+    time_last_checkpoint_end = time(NULL);
+    time_last_checkpoint_begin_complete = time_last_checkpoint_begin;
     checkpoint_safe_checkpoint_unlock();
     checkpoint_footprint = 0;
 

newbrt/checkpoint.h

@@ -66,6 +66,14 @@ int toku_checkpoint(CACHETABLE ct, TOKULOGGER logger, char **error_string,
  * Some status information may be incorrect because no locks are taken to collect status.
  * (If checkpoint is in progress, it may overwrite status info while it is being read.)
  *****/
+typedef struct {
+    u_int32_t footprint;
+    time_t time_last_checkpoint_begin_complete;
+    time_t time_last_checkpoint_begin;
+    time_t time_last_checkpoint_end;
+} CHECKPOINT_STATUS_S, *CHECKPOINT_STATUS;
+
+void toku_checkpoint_get_status(CHECKPOINT_STATUS stat);
+
 
-u_int32_t toku_checkpoint_get_footprint(void);
 

src/ydb.c

@@ -958,6 +958,22 @@ locked_env_set_default_bt_compare(DB_ENV * env, int (*bt_compare) (DB *, const D
     return r;
 }
 
+static void
+format_time(const time_t *timer, char *buf) {
+    ctime_r(timer, buf);
+    size_t len = strlen(buf);
+    assert(len < 26);
+    char end;
+
+    assert(len>=1);
+    end = buf[len-1];
+    while (end == '\n' || end == '\r') {
+        buf[len-1] = '\0';
+        len--;
+        assert(len>=1);
+        end = buf[len-1];
+    }
+}
 
 // Do not take ydb lock around or in this function.  
 // If the engine is blocked because some thread is holding the ydb lock, this function
@@ -970,9 +986,18 @@ env_get_engine_status(DB_ENV * env, ENGINE_STATUS * engstat) {
     int r = 0;
     if (!env_opened(env)) r = EINVAL;
     else {
+	time_t now = time(NULL);
+        format_time(&now, engstat->now);
 	engstat->ydb_lock_ctr = toku_ydb_lock_ctr();                       // is ydb lock held? how many times?
 	env_checkpointing_get_period(env, &(engstat->checkpoint_period));  // do not take ydb lock (take minicron lock, but that's a very ephemeral low-level lock)
-	engstat->checkpoint_footprint = toku_checkpoint_get_footprint();
+	{
+            CHECKPOINT_STATUS_S cpstat;
+            toku_checkpoint_get_status(&cpstat);
+            engstat->checkpoint_footprint = cpstat.footprint;
+	    format_time(&cpstat.time_last_checkpoint_begin_complete, engstat->checkpoint_time_begin_complete);
+	    format_time(&cpstat.time_last_checkpoint_begin,          engstat->checkpoint_time_begin);
+	    format_time(&cpstat.time_last_checkpoint_end,            engstat->checkpoint_time_end);
+	}
 	{
 	    CACHETABLE_STATUS_S ctstat;
 	    toku_cachetable_get_status(env->i->cachetable, &ctstat);

windows/misc.h

@@ -16,6 +16,8 @@ int fsync(int fildes);
 
 int gettimeofday(struct timeval *tv, struct timezone *tz);
 
+char * ctime_r(const time_t *timep, char *buf);
+
 long long int strtoll(const char *nptr, char **endptr, int base);
 
 

windows/toku_time.c

@@ -46,3 +46,11 @@ clock_gettime(clockid_t clockid, toku_timespec_t *ts) {
     else
         return -1;
 }
+
+char *
+ctime_r(const time_t *timep, char *buf) {
+    int r = ctime_s(buf, 26, timep);
+    assert(r == 0);
+    return buf;
+}
+