Merge pull request #3285 from Carbenium/time-event

Convert Event and Logger internals to std::chrono

src/zm_event.cpp

@@ -49,8 +49,8 @@ Event::Event(
     ) :
   id(0),
   monitor(p_monitor),
-  start_time(p_start_time),
+  start_time(SystemTimePoint(zm::chrono::duration_cast<Microseconds>(p_start_time))),
-  end_time({0,0}),
+  end_time(),
   cause(p_cause),
   noteSetMap(p_noteSetMap),
   frames(0),
@@ -72,25 +72,25 @@ Event::Event(
   std::string notes;
   createNotes(notes);
 
-  timeval now = {};
+  SystemTimePoint now = std::chrono::system_clock::now();
-  gettimeofday(&now, nullptr);
 
-  if ( !start_time.tv_sec ) {
+  if (start_time.time_since_epoch() == Seconds(0)) {
     Warning("Event has zero time, setting to now");
     start_time = now;
-  } else if ( start_time.tv_sec > now.tv_sec ) {
+  } else if (start_time > now) {
     char buffer[26];
     char buffer_now[26];
     tm tm_info = {};
+    time_t start_time_t = std::chrono::system_clock::to_time_t(start_time);
+    time_t now_t = std::chrono::system_clock::to_time_t(now);
 
-    localtime_r(&start_time.tv_sec, &tm_info);
+    localtime_r(&start_time_t, &tm_info);
     strftime(buffer, 26, "%Y:%m:%d %H:%M:%S", &tm_info);
-    localtime_r(&now.tv_sec, &tm_info);
+    localtime_r(&now_t, &tm_info);
     strftime(buffer_now, 26, "%Y:%m:%d %H:%M:%S", &tm_info);
 
-    Error("StartDateTime in the future starttime %ld.%06ld >? now %ld.%06ld difference %" PRIi64 "\nstarttime: %s\nnow: %s",
+    Error("StartDateTime in the future. Difference: %" PRIi64 " s\nstarttime: %s\nnow: %s",
-          start_time.tv_sec, start_time.tv_usec, now.tv_sec, now.tv_usec,
+          static_cast<int64>(std::chrono::duration_cast<Seconds>(now - start_time).count()),
-          static_cast<int64>(now.tv_sec - start_time.tv_sec),
           buffer, buffer_now);
     start_time = now;
   }
@@ -114,7 +114,7 @@ Event::Event(
       "( %d, %d, 'New Event', from_unixtime( %ld ), %d, %d, '%s', '%s', %d, %d, %d, '%s', %d, '%s' )",
       monitor->Id(), 
       storage->Id(),
-      start_time.tv_sec,
+      static_cast<int64>(std::chrono::system_clock::to_time_t(start_time)),
       monitor->Width(),
       monitor->Height(),
       cause.c_str(),
@@ -233,18 +233,15 @@ Event::~Event() {
   }
 
   // endtime is set in AddFrame, so SHOULD be set to the value of the last frame timestamp.
-  if ( !end_time.tv_sec ) {
+  if (end_time.time_since_epoch() == Seconds(0)) {
     Warning("Empty endtime for event. Should not happen. Setting to now.");
-    gettimeofday(&end_time, nullptr);
+    end_time = std::chrono::system_clock::now();
   }
 
-  FPSeconds delta_time =
+  FPSeconds delta_time = end_time - start_time;
-      zm::chrono::duration_cast<Microseconds>(end_time) - zm::chrono::duration_cast<Microseconds>(start_time);
+  Debug(2, "start_time: %.2f end_time: %.2f",
-  Debug(2, "start_time: %" PRIi64 ".% " PRIi64 " end_time: %" PRIi64 ".%" PRIi64,
+        std::chrono::duration_cast<FPSeconds>(start_time.time_since_epoch()).count(),
-        static_cast<int64>(start_time.tv_sec),
+        std::chrono::duration_cast<FPSeconds>(end_time.time_since_epoch()).count());
-        static_cast<int64>(start_time.tv_usec),
-        static_cast<int64>(end_time.tv_sec),
-        static_cast<int64>(end_time.tv_usec));
 
   if (frame_data.size()){
     WriteDbFrames();
@@ -252,7 +249,7 @@ Event::~Event() {
 
   std::string sql = stringtf(
       "UPDATE Events SET Name='%s%" PRIu64 "', EndDateTime = from_unixtime(%ld), Length = %.2f, Frames = %d, AlarmFrames = %d, TotScore = %d, AvgScore = %d, MaxScore = %d WHERE Id = %" PRIu64 " AND Name='New Event'",
-      monitor->EventPrefix(), id, end_time.tv_sec,
+      monitor->EventPrefix(), id, std::chrono::system_clock::to_time_t(end_time),
       delta_time.count(),
       frames, alarm_frames,
       tot_score, static_cast<uint32>(alarm_frames ? (tot_score / alarm_frames) : 0), max_score,
@@ -262,7 +259,7 @@ Event::~Event() {
     // Name might have been changed during recording, so just do the update without changing the name.
     sql = stringtf(
         "UPDATE Events SET EndDateTime = from_unixtime(%ld), Length = %.2f, Frames = %d, AlarmFrames = %d, TotScore = %d, AvgScore = %d, MaxScore = %d WHERE Id = %" PRIu64,
-        end_time.tv_sec,
+        std::chrono::system_clock::to_time_t(end_time),
         delta_time.count(),
         frames, alarm_frames,
         tot_score, static_cast<uint32>(alarm_frames ? (tot_score / alarm_frames) : 0), max_score,
@@ -422,13 +419,13 @@ void Event::updateNotes(const StringSetMap &newNoteSetMap) {
 }  // void Event::updateNotes(const StringSetMap &newNoteSetMap)
 
 void Event::AddPacket(const std::shared_ptr<ZMPacket>&packet) {
-
   have_video_keyframe = have_video_keyframe || 
     ( ( packet->codec_type == AVMEDIA_TYPE_VIDEO ) && 
       ( packet->keyframe || monitor->GetOptVideoWriter() == Monitor::ENCODE) );
   Debug(2, "have_video_keyframe %d codec_type %d == video? %d packet keyframe %d",
       have_video_keyframe, packet->codec_type, (packet->codec_type == AVMEDIA_TYPE_VIDEO), packet->keyframe);
   ZM_DUMP_PACKET(packet->packet, "Adding to event");
+
   if (videoStore) {
     if (have_video_keyframe) {
       videoStore->writePacket(packet);
@@ -437,10 +434,11 @@ void Event::AddPacket(const std::shared_ptr<ZMPacket>&packet) {
     }
     //FIXME if it fails, we should write a jpeg
   }
-  if ((packet->codec_type == AVMEDIA_TYPE_VIDEO) or packet->image)
+
+  if ((packet->codec_type == AVMEDIA_TYPE_VIDEO) or packet->image) {
     AddFrame(packet->image, packet->timestamp, packet->zone_stats, packet->score, packet->analysis_image);
-  end_time = packet->timestamp;
+  }
-  return;
+  end_time = SystemTimePoint(zm::chrono::duration_cast<Microseconds>(packet->timestamp));
 }
 
 void Event::WriteDbFrames() {
@@ -577,12 +575,13 @@ void Event::AddFrame(
     or ( monitor_state == Monitor::ALARM )
     or ( monitor_state == Monitor::PREALARM );
 
+  SystemTimePoint timestamp_us = SystemTimePoint(zm::chrono::duration_cast<Microseconds>(timestamp));
+
   if (db_frame) {
-    FPSeconds delta_time =
+    FPSeconds delta_time = timestamp_us - start_time;
-        zm::chrono::duration_cast<Microseconds>(timestamp) - zm::chrono::duration_cast<Microseconds>(start_time);
+    Debug(1, "Frame delta is %.2f - %.2f = %.2f, score %u zone_stats.size %zu",
-    Debug(1, "Frame delta is %" PRIi64 ".%" PRIi64 " - %" PRIi64 ".%" PRIi64 " = %.2f, score %u zone_stats.size %zu",
+          std::chrono::duration_cast<FPSeconds>(timestamp_us.time_since_epoch()).count(),
-          static_cast<int64>(start_time.tv_sec), static_cast<int64>(start_time.tv_usec),
+          std::chrono::duration_cast<FPSeconds>(start_time.time_since_epoch()).count(),
-          static_cast<int64>(timestamp.tv_sec), static_cast<int64>(timestamp.tv_usec),
           delta_time.count(),
           score,
           zone_stats.size());
@@ -622,7 +621,7 @@ void Event::AddFrame(
   if (score > (int) max_score) {
     max_score = score;
   }
-  end_time = timestamp;
+  end_time = timestamp_us;
 }  // end void Event::AddFrame(Image *image, struct timeval timestamp, int score, Image *alarm_image)
 
 bool Event::SetPath(Storage *storage) {
@@ -635,8 +634,10 @@ bool Event::SetPath(Storage *storage) {
     return false;
   }
 
+  time_t start_time_t = std::chrono::system_clock::to_time_t(start_time);
+
   tm stime = {};
-  localtime_r(&start_time.tv_sec, &stime);
+  localtime_r(&start_time_t, &stime);
   if (scheme == Storage::DEEP) {
 
     int dt_parts[6];

src/zm_event.h

@@ -23,6 +23,7 @@
 #include "zm_config.h"
 #include "zm_define.h"
 #include "zm_storage.h"
+#include "zm_time.h"
 #include "zm_zone.h"
 
 #include <map>
@@ -68,8 +69,8 @@ class Event {
 
     uint64_t  id;
     Monitor      *monitor;
-    struct timeval  start_time;
+    SystemTimePoint start_time;
-    struct timeval  end_time;
+    SystemTimePoint end_time;
     std::string     cause;
     StringSetMap    noteSetMap;
     int        frames;
@@ -108,8 +109,8 @@ class Event {
     int Frames() const { return frames; }
     int AlarmFrames() const { return alarm_frames; }
 
-    const struct timeval &StartTime() const { return start_time; }
+    timeval StartTime() const { return zm::chrono::duration_cast<timeval>(start_time.time_since_epoch()); }
-    const struct timeval &EndTime() const { return end_time; }
+    timeval EndTime() const { return zm::chrono::duration_cast<timeval>(end_time.time_since_epoch()); }
 
     void AddPacket(const std::shared_ptr<ZMPacket> &p);
     bool WritePacket(const std::shared_ptr<ZMPacket> &p);

src/zm_logger.cpp

@@ -20,10 +20,10 @@
 #include "zm_logger.h"
 
 #include "zm_db.h"
+#include "zm_time.h"
 #include "zm_utils.h"
 #include <libgen.h>
 #include <syslog.h>
-#include <sys/time.h>
 #include <unistd.h>
 
 #ifdef __FreeBSD__
@@ -425,30 +425,20 @@ void Logger::logPrint(bool hex, const char *filepath, int line, int level, const
   char            timeString[64];
   char            logString[4096]; // SQL TEXT can hold 64k so we could go up to 32k here but why?
   va_list         argPtr;
-  struct timeval  timeVal;
 
   const char *base = strrchr(filepath, '/');
   const char *file = base ? base+1 : filepath;
   const char *classString = smCodes[level].c_str();
 
-  gettimeofday(&timeVal, nullptr);
+  SystemTimePoint now = std::chrono::system_clock::now();
+  time_t now_sec = std::chrono::system_clock::to_time_t(now);
+  Microseconds now_frac = std::chrono::duration_cast<Microseconds>(
+      now.time_since_epoch() - std::chrono::duration_cast<Seconds>(now.time_since_epoch()));
 
-#if 0
-  if ( logRuntime ) {
-    static struct timeval logStart;
-
-    subtractTime( &timeVal, &logStart );
-
-    snprintf( timeString, sizeof(timeString), "%ld.%03ld", timeVal.tv_sec, timeVal.tv_usec/1000 );
-  } else {
-#endif
   char *timePtr = timeString;
   tm now_tm = {};
-    timePtr += strftime(timePtr, sizeof(timeString), "%x %H:%M:%S", localtime_r(&timeVal.tv_sec, &now_tm));
+  timePtr += strftime(timePtr, sizeof(timeString), "%x %H:%M:%S", localtime_r(&now_sec, &now_tm));
-    snprintf(timePtr, sizeof(timeString)-(timePtr-timeString), ".%06ld", timeVal.tv_usec);
+  snprintf(timePtr, sizeof(timeString) - (timePtr - timeString), ".%06" PRIi64, static_cast<int64>(now_frac.count()));
-#if 0
-  }
-#endif
 
   pid_t tid;
 #ifdef __FreeBSD__
@@ -539,8 +529,8 @@ void Logger::logPrint(bool hex, const char *filepath, int line, int level, const
           "( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` )"
           " VALUES "
           "( %ld.%06ld, '%s', %d, %d, %d, '%s', '%s', '%s', %d )",
-          timeVal.tv_sec, timeVal.tv_usec, mId.c_str(), staticConfig.SERVER_ID, tid, level, classString, escapedString.c_str(), file, line
+          now_sec, now_frac.count(), mId.c_str(), staticConfig.SERVER_ID, tid, level, classString,
-          );
+          escapedString.c_str(), file, line);
       dbQueue.push(std::move(sql_string));
     } else {
       puts("Db is closed");