L2SDP-377, add time information in logging and corrected usec with leading zeros.

src/periph/fpga.cpp

@@ -225,7 +225,7 @@ uint32_t Periph_fpga::shift_mask(const string addr_str, uint32_t data)
 */
 bool Periph_fpga::read_system_info(TermOutput& termout)
 {
-    cout << "node " << GlobalNr << " read system info" << endl;
+    // cout << "node " << GlobalNr << " read system info" << endl;
     uint32_t data;
     bool retval = Read("mm/0/PIO_SYSTEM_INFO/0/info", &data);
     if (retval == false) {
@@ -587,7 +587,8 @@ bool Periph_fpga::monitor(TermOutput& termout)
     if (!Enabled) { return false; }
     // use tictoc, tic(start) toc(stop) to see how long this function takes
     // first 9 read functions on 4 nodes will take 6 msec.
-    tictoc.tic("periph.fpga.monitor");
+    string name = "periph.fpga.monitor node " + to_string(GlobalNr);
+    tictoc.tic(name.c_str());
     read_system_info(termout);
     if (Online) {
         read_time_since_last_pps(termout, REG_FORMAT_INT64, R_UCP);

src/sdptr.cpp

@@ -63,6 +63,9 @@ void monitor()
     string cmdname = "";
     TermOutput termout;
     struct timeval current_time;
+    time_t secs;
+    struct tm * now;
+    char time_str[50];
 
     SD.timetick = SECONDS_PER_TICK;
     clock_gettime(CLOCK_REALTIME, (struct timespec *)&SD.t0);
@@ -84,10 +87,14 @@ void monitor()
 
         gettimeofday(&current_time, NULL);
         SD.tod = current_time.tv_sec;
-        cout << "MONITOR THREAD. now=" << current_time.tv_sec << "." << current_time.tv_usec
-                  << " uptime=" << SD.uptime << " seconds" << endl;
         SD.uptime++;
 
+        secs = current_time.tv_sec;
+        now = gmtime(&secs);
+        sprintf(time_str, "%02d:%02d:%02d.%06ld", now->tm_hour, now->tm_min, now->tm_sec, current_time.tv_usec);
+
+        cout << "[" << time_str << " (UTC)] " << "MONITOR THREAD: uptime=" << SD.uptime << " seconds" << endl;
+
         if (SD.unb != NULL) {
             // cout << "sdptr_monitor start" << endl;
             SD.unb->monitor(termout);

src/tools/util.cpp

@@ -29,6 +29,8 @@
 #include <cmath>
 #include <iostream>
 #include <algorithm>
+#include <ctime>
+#include <sys/time.h>
 
 #include "util.h"
 
@@ -97,7 +99,7 @@ vector<uint> unique_and_sort(vector<uint> v)
 void Tictoc::tic(string idstr)
 {
     name = idstr;
-    cout << "tic: start [" << name << "]" << endl;
+    // cout << "tic: start [" << name << "]" << endl;
     c_start = clock();
     t_start = chrono::high_resolution_clock::now();
 }
@@ -106,6 +108,15 @@ void Tictoc::toc(void)
 {
     clock_t c_end = clock();
     auto t_end = chrono::high_resolution_clock::now();
+    
+    struct timeval tv;
+    gettimeofday(&tv, NULL);
+    time_t secs = tv.tv_sec;
+    struct tm * now = gmtime(&secs);
+    char time_str[50];
+    sprintf(time_str, "%02d:%02d:%02d.%06ld", now->tm_hour, now->tm_min, now->tm_sec, tv.tv_usec);
+    
+    cout << "[" << time_str << " (UTC)] ";
     cout << "toc-tic (" << name << ") CPU time: " << 1000.0 * (c_end-c_start) / CLOCKS_PER_SEC << " ms. ";
     cout << "Real time: "
               << chrono::duration_cast<chrono::milliseconds>(t_end - t_start).count()