Optimize logfile write (#1652)

* remove no longer needed OpenFileAndWait()

* remove WriteToDedicatedFile

* .

Co-authored-by: CaCO3 <caco@ruinelli.ch>

code/components/jomjol_configfile/configFile.cpp

@@ -13,7 +13,7 @@ static const char *TAG = "CONFIG";
 ConfigFile::ConfigFile(std::string filePath)
 {
     std::string config = FormatFileName(filePath);
-    pFile = OpenFileAndWait(config.c_str(), "r");
+    pFile = fopen(config.c_str(), "r");
 }
 
 ConfigFile::~ConfigFile()

code/components/jomjol_controlcamera/ClassControllCamera.cpp

@@ -391,7 +391,7 @@ esp_err_t CCamera::CaptureToFile(std::string nm, int delay)
         }
     }
 
-    FILE * fp = OpenFileAndWait(nm.c_str(), "wb");
+    FILE * fp = fopen(nm.c_str(), "wb");
     if (fp == NULL)  /* If an error occurs during the file creation */
     {
         fprintf(stderr, "fopen() failed for '%s'\n", nm.c_str());

code/components/jomjol_fileserver_ota/server_file.cpp

@@ -217,7 +217,7 @@ static esp_err_t http_resp_dir_html(httpd_req_t *req, const char *dirpath, const
 
 /////////////////////////////////////////////////
     if (!readonly) {
-        FILE *fd = OpenFileAndWait("/sdcard/html/upload_script.html", "r");
+        FILE *fd = fopen("/sdcard/html/upload_script.html", "r");
         char *chunk = ((struct file_server_data *)req->user_ctx)->scratch;
         size_t chunksize;
         do {
@@ -346,7 +346,11 @@ static esp_err_t send_datafile(httpd_req_t *req, bool send_full_file)
 
     httpd_resp_set_hdr(req, "Access-Control-Allow-Origin", "*");
 
-    fd = OpenFileAndWait(currentfilename.c_str(), "r");
+
+    // Since the log file is still open for writing, we need to close it first
+    LogFile.CloseLogFileAppendHandle();
+
+    fd = fopen(currentfilename.c_str(), "r");
     if (!fd) {
         LogFile.WriteToFile(ESP_LOG_ERROR, TAG, "Failed to read existing file: " + std::string(filepath) +"!");
         /* Respond with 404 Error */
@@ -431,7 +435,7 @@ static esp_err_t send_logfile(httpd_req_t *req, bool send_full_file)
     ESP_LOGD(TAG, "uri: %s, filename: %s, filepath: %s", req->uri, filename, filepath);
 
 
-    fd = OpenFileAndWait(currentfilename.c_str(), "r");
+    fd = fopen(currentfilename.c_str(), "r");
     if (!fd) {
         LogFile.WriteToFile(ESP_LOG_ERROR, TAG, "Failed to read existing file: " + std::string(filepath) +"!");
         /* Respond with 404 Error */
@@ -559,7 +563,7 @@ static esp_err_t download_get_handler(httpd_req_t *req)
         return ESP_FAIL;
     }
 
-    fd = OpenFileAndWait(filepath, "r");
+    fd = fopen(filepath, "r");
     if (!fd) {
         LogFile.WriteToFile(ESP_LOG_ERROR, TAG, "Failed to read existing file: " + std::string(filepath) +"!");
         /* Respond with 404 Error */
@@ -647,7 +651,7 @@ static esp_err_t upload_post_handler(httpd_req_t *req)
         return ESP_FAIL;
     }
 
-    fd = OpenFileAndWait(filepath, "w");
+    fd = fopen(filepath, "w");
     if (!fd) {
         ESP_LOGE(TAG, "Failed to create file: %s", filepath);
         /* Respond with 500 Internal Server Error */
@@ -980,7 +984,7 @@ std::string unzip_new(std::string _in_zip_file, std::string _target_zip, std::st
 
                 // extrahieren in zwischendatei
                 DeleteFile(filename_zw);
-                FILE* fpTargetFile = OpenFileAndWait(filename_zw.c_str(), "wb");
+                FILE* fpTargetFile = fopen(filename_zw.c_str(), "wb");
                 uint writtenbytes = fwrite(p, 1, (uint)uncomp_size, fpTargetFile);
                 fclose(fpTargetFile);
                 
@@ -1079,7 +1083,7 @@ void unzip(std::string _in_zip_file, std::string _target_directory){
             zw = std::string(archive_filename);
             zw = _target_directory + zw;
             ESP_LOGD(TAG, "Filename to extract: %s", zw.c_str());
-            FILE* fpTargetFile = OpenFileAndWait(zw.c_str(), "wb");
+            FILE* fpTargetFile = fopen(zw.c_str(), "wb");
             fwrite(p, 1, (uint)uncomp_size, fpTargetFile);
             fclose(fpTargetFile);
 

code/components/jomjol_fileserver_ota/server_help.cpp

@@ -30,7 +30,7 @@ char scratch[SERVER_HELPER_SCRATCH_BUFSIZE];
 
 esp_err_t send_file(httpd_req_t *req, std::string filename)
 {
-    FILE *fd = OpenFileAndWait(filename.c_str(), "r");
+    FILE *fd = fopen(filename.c_str(), "r");
     if (!fd) {
         ESP_LOGE(TAG, "Failed to read existing file: %s", filename.c_str());
         /* Respond with 404 Error */

code/components/jomjol_fileserver_ota/server_ota.cpp

@@ -154,7 +154,7 @@ static bool ota_update_task(std::string fn)
 
     int data_read;     
 
-    FILE* f = OpenFileAndWait(fn.c_str(), "rb");     // previously only "r
+    FILE* f = fopen(fn.c_str(), "rb");     // previously only "r
 
     if (f == NULL) { // File does not exist
         return false;

code/components/jomjol_flowcontroll/ClassFlowAlignment.cpp

@@ -273,34 +273,21 @@ bool ClassFlowAlignment::LoadReferenceAlignmentValues(void)
     std::vector<string> splitted;  
 
 
-//    LogFile.WriteToDedicatedFile("/sdcard/alignment.txt", "LoadReferenceAlignmentValues01");      
-
     pFile = fopen(FileStoreRefAlignment.c_str(), "r");
     if (pFile == NULL)
         return false;
 
-//    LogFile.WriteToDedicatedFile("/sdcard/alignment.txt", "LoadReferenceAlignmentValues01");      
-
     fgets(zw, 1024, pFile);
     ESP_LOGD(TAG, "%s", zw);
 
-//    zwvalue = "LoadReferenceAlignmentValues Time: " + std::string(zw);
-
-//    LogFile.WriteToDedicatedFile("/sdcard/alignment.txt", zwvalue);      
-
-//    LogFile.WriteToDedicatedFile("/sdcard/alignment.txt", "LoadReferenceAlignmentValues02");      
-
     fgets(zw, 1024, pFile);
     splitted = ZerlegeZeile(std::string(zw), " \t");
     if (splitted.size() < 6)
     {
-//        LogFile.WriteToDedicatedFile("/sdcard/alignment.txt", "Exit 01");      
         fclose(pFile);
         return false;
     }
 
-//    LogFile.WriteToDedicatedFile("/sdcard/alignment.txt", "LoadReferenceAlignmentValues03");      
-
     References[0].fastalg_x = stoi(splitted[0]);
     References[0].fastalg_y = stoi(splitted[1]);
     References[0].fastalg_SAD = stof(splitted[2]);
@@ -312,13 +299,10 @@ bool ClassFlowAlignment::LoadReferenceAlignmentValues(void)
     splitted = ZerlegeZeile(std::string(zw));
     if (splitted.size() < 6)
     {
-//        LogFile.WriteToDedicatedFile("/sdcard/alignment.txt", "Exit 02");      
         fclose(pFile);
         return false;
     }
 
-//    LogFile.WriteToDedicatedFile("/sdcard/alignment.txt", "LoadReferenceAlignmentValues03");      
-
     References[1].fastalg_x = stoi(splitted[0]);
     References[1].fastalg_y = stoi(splitted[1]);
     References[1].fastalg_SAD = stof(splitted[2]);
@@ -329,7 +313,7 @@ bool ClassFlowAlignment::LoadReferenceAlignmentValues(void)
     fclose(pFile);
 
 
-#ifdef DEBUG_DETAIL_ON  
+/*#ifdef DEBUG_DETAIL_ON
     std::string _zw = "\tLoadReferences[0]\tx,y:\t" + std::to_string(References[0].fastalg_x) + "\t" + std::to_string(References[0].fastalg_x);
     _zw = _zw + "\tSAD, min, max, avg:\t" + std::to_string(References[0].fastalg_SAD) + "\t" + std::to_string(References[0].fastalg_min);
     _zw = _zw + "\t" + std::to_string(References[0].fastalg_max) + "\t" + std::to_string(References[0].fastalg_avg);
@@ -338,7 +322,7 @@ bool ClassFlowAlignment::LoadReferenceAlignmentValues(void)
     _zw = _zw + "\tSAD, min, max, avg:\t" + std::to_string(References[1].fastalg_SAD) + "\t" + std::to_string(References[1].fastalg_min);
     _zw = _zw + "\t" + std::to_string(References[1].fastalg_max) + "\t" + std::to_string(References[1].fastalg_avg);
     LogFile.WriteToDedicatedFile("/sdcard/alignment.txt", _zw);
-#endif
+#endif*/
 
     return true;
 }

code/components/jomjol_flowcontroll/ClassFlowControll.cpp

@@ -247,7 +247,7 @@ void ClassFlowControll::InitFlow(std::string config)
     ClassFlow* cfc;
     FILE* pFile;
     config = FormatFileName(config);
-    pFile = OpenFileAndWait(config.c_str(), "r");
+    pFile = fopen(config.c_str(), "r");
 
     line = "";
 

code/components/jomjol_helper/Helper.cpp

@@ -167,24 +167,6 @@ void memCopyGen(uint8_t* _source, uint8_t* _target, int _size)
 }
 
 
-
-FILE* OpenFileAndWait(const char* nm, const char* _mode, int _waitsec, bool silent)
-{
-	FILE *pfile;
-
-	ESP_LOGD(TAG, "open file %s in mode %s", nm, _mode);
-
-	if ((pfile = fopen(nm, _mode)) != NULL) {
-		if (!silent) ESP_LOGE(TAG, "File %s successfully opened", nm);
-	}
-	else {
-		if (!silent) ESP_LOGE(TAG, "Error: file %s does not exist!", nm);
-		return NULL;
-	}
-
-	return pfile;
-}
-
 std::string FormatFileName(std::string input)
 {
 #ifdef ISWINDOWS_TRUE
@@ -307,7 +289,7 @@ bool RenameFile(string from, string to)
 {
 //	ESP_LOGI(logTag, "Deleting file: %s", fn.c_str());
 	/* Delete file */
-	FILE* fpSourceFile = OpenFileAndWait(from.c_str(), "rb");
+	FILE* fpSourceFile = fopen(from.c_str(), "rb");
 	if (!fpSourceFile)	// Sourcefile existiert nicht sonst gibt es einen Fehler beim Kopierversuch!
 	{
 		ESP_LOGE(TAG, "DeleteFile: File %s existiert nicht!", from.c_str());
@@ -324,7 +306,7 @@ bool DeleteFile(string fn)
 {
 //	ESP_LOGI(logTag, "Deleting file: %s", fn.c_str());
 	/* Delete file */
-	FILE* fpSourceFile = OpenFileAndWait(fn.c_str(), "rb");
+	FILE* fpSourceFile = fopen(fn.c_str(), "rb");
 	if (!fpSourceFile)	// Sourcefile existiert nicht sonst gibt es einen Fehler beim Kopierversuch!
 	{
 		ESP_LOGD(TAG, "DeleteFile: File %s existiert nicht!", fn.c_str());
@@ -349,14 +331,14 @@ bool CopyFile(string input, string output)
 	}
 
 	char cTemp;
-	FILE* fpSourceFile = OpenFileAndWait(input.c_str(), "rb");
+	FILE* fpSourceFile = fopen(input.c_str(), "rb");
 	if (!fpSourceFile)	// Sourcefile existiert nicht sonst gibt es einen Fehler beim Kopierversuch!
 	{
 		ESP_LOGD(TAG, "File %s existiert nicht!", input.c_str());
 		return false;
 	}
 
-	FILE* fpTargetFile = OpenFileAndWait(output.c_str(), "wb");
+	FILE* fpTargetFile = fopen(output.c_str(), "wb");
 
 	// Code Section
 

code/components/jomjol_helper/Helper.h

@@ -22,9 +22,6 @@ bool MakeDir(std::string _what);
 
 string RundeOutput(double _in, int _anzNachkomma);
 
-
-FILE* OpenFileAndWait(const char* nm, const char* _mode, int _waitsec = 1, bool silent = true);
-
 size_t findDelimiterPos(string input, string delimiter);
 //string trim(string istring);
 string trim(string istring, string adddelimiter = "");

code/components/jomjol_image_proc/CAlignAndCutImage.cpp

@@ -72,14 +72,14 @@ bool CAlignAndCutImage::Align(RefInfo *_temp1, RefInfo *_temp2)
 
     d_winkel = (w_ist - w_org) * 180 / M_PI;
 
-#ifdef DEBUG_DETAIL_ON
+/*#ifdef DEBUG_DETAIL_ON
     std::string zw = "\tdx:\t" + std::to_string(dx) + "\tdy:\t" + std::to_string(dy) + "\td_winkel:\t" + std::to_string(d_winkel);
     zw = zw + "\tt1_x_y:\t" + std::to_string(_temp1->found_x) + "\t" + std::to_string(_temp1->found_y);
     zw = zw + "\tpara1_found_min_avg_max_SAD:\t" + std::to_string(_temp1->fastalg_min) + "\t" + std::to_string(_temp1->fastalg_avg) + "\t" + std::to_string(_temp1->fastalg_max) + "\t"+ std::to_string(_temp1->fastalg_SAD);
     zw = zw + "\tt2_x_y:\t" + std::to_string(_temp2->found_x) + "\t" + std::to_string(_temp2->found_y);
     zw = zw + "\tpara2_found_min_avg_max:\t" + std::to_string(_temp2->fastalg_min) + "\t" + std::to_string(_temp2->fastalg_avg) + "\t" + std::to_string(_temp2->fastalg_max) + "\t"+ std::to_string(_temp2->fastalg_SAD);
     LogFile.WriteToDedicatedFile("/sdcard/alignment.txt", zw);
-#endif
+#endif*/
 
     CRotateImage rt(this, ImageTMP);
     rt.Translate(dx, dy);

code/components/jomjol_image_proc/CFindTemplate.cpp

@@ -68,11 +68,11 @@ bool CFindTemplate::FindTemplate(RefInfo *_ref)
     if ((_ref->alignment_algo == 2) && (_ref->fastalg_x > -1) && (_ref->fastalg_y > -1))     // für Testzwecke immer Berechnen
     {
         isSimilar = CalculateSimularities(rgb_template, _ref->fastalg_x, _ref->fastalg_y, ow, oh, min, avg, max, SAD, _ref->fastalg_SAD, _ref->fastalg_SAD_criteria);
-#ifdef DEBUG_DETAIL_ON  
+/*#ifdef DEBUG_DETAIL_ON
         std::string zw = "\t" + _ref->image_file + "\tt1_x_y:\t" + std::to_string(_ref->fastalg_x) + "\t" + std::to_string(_ref->fastalg_y);
         zw = zw + "\tpara1_found_min_avg_max_SAD:\t" + std::to_string(min) + "\t" + std::to_string(avg) + "\t" + std::to_string(max) + "\t"+ std::to_string(SAD);
         LogFile.WriteToDedicatedFile("/sdcard/alignment.txt", zw);
-#endif
+#endif*/
     }
 
 //    ESP_LOGD(TAG, "FindTemplate 03");
@@ -144,11 +144,11 @@ bool CFindTemplate::FindTemplate(RefInfo *_ref)
     _ref->fastalg_SAD = SAD;
 
     
-#ifdef DEBUG_DETAIL_ON  
+/*#ifdef DEBUG_DETAIL_ON
     std::string zw = "\t" + _ref->image_file + "\tt1_x_y:\t" + std::to_string(_ref->fastalg_x) + "\t" + std::to_string(_ref->fastalg_y);
     zw = zw + "\tpara1_found_min_avg_max_SAD:\t" + std::to_string(min) + "\t" + std::to_string(avg) + "\t" + std::to_string(max) + "\t"+ std::to_string(SAD);
     LogFile.WriteToDedicatedFile("/sdcard/alignment.txt", zw);
-#endif
+#endif*/
 
     RGBImageRelease();
     stbi_image_free(rgb_template);

code/components/jomjol_logfile/ClassLogFile.cpp

@@ -112,69 +112,6 @@ void ClassLogFile::WriteToData(std::string _timestamp, std::string _name, std::s
 }
 
 
-void ClassLogFile::WriteToDedicatedFile(std::string _fn, esp_log_level_t level, std::string message, bool _time)
-{
-    FILE* pFile;
-    std::string zwtime;
-    std::string ntpTime = "";
-
-    if (level > loglevel) {// Only write to file if loglevel is below threshold
-        return;
-    }
-
-//    pFile = OpenFileAndWait(_fn.c_str(), "a"); 
-    pFile = fopen(_fn.c_str(), "a+");
-//    ESP_LOGD(TAG, "Logfile opened: %s", _fn.c_str());
-
-    if (pFile!=NULL) {
-        if (_time)
-        {
-            time_t rawtime;
-            struct tm* timeinfo;
-            char buffer[80];
-
-            time(&rawtime);
-            timeinfo = localtime(&rawtime);
-
-            strftime(buffer, 80, "%Y-%m-%dT%H:%M:%S", timeinfo);
-
-            zwtime = std::string(buffer);
-            ntpTime = zwtime;
-        }
-
-        std::string loglevelString; 
-        switch(level) {
-            case  ESP_LOG_ERROR:
-                loglevelString = "ERR";
-                break;
-            case  ESP_LOG_WARN:
-                loglevelString = "WRN";
-                break;
-            case  ESP_LOG_INFO:
-                loglevelString = "INF";
-                break;
-            case  ESP_LOG_DEBUG:
-                loglevelString = "DBG";
-                break;
-            case  ESP_LOG_VERBOSE:
-                loglevelString = "VER";
-                break;
-            case  ESP_LOG_NONE:
-            default:
-                loglevelString = "NONE";
-                break;
-        }
-
-        std::string formatedUptime = getFormatedUptime(true);
-
-        ntpTime = "[" + formatedUptime + "] "  + ntpTime + "\t<" + loglevelString + ">\t" + message + "\n";
-        fputs(ntpTime.c_str(), pFile);
-        fclose(pFile);    
-    } else {
-        ESP_LOGE(TAG, "Can't open log file %s", _fn.c_str());
-    }
-}
-
 void ClassLogFile::setLogLevel(esp_log_level_t _logLevel){
     loglevel = _logLevel;
 
@@ -224,26 +161,25 @@ bool ClassLogFile::GetDataLogToSD(){
     return doDataLogToSD;
 }
 
+static FILE* logFileAppendHande = NULL;
+std::string fileNameDate;
+
+
 void ClassLogFile::WriteToFile(esp_log_level_t level, std::string tag, std::string message, bool _time)
 {
-/*
-    struct stat path_stat;
-    if (stat(logroot.c_str(), &path_stat) != 0) {
-        ESP_LOGI(TAG, "Create log folder: %s", logroot.c_str());
-        if (mkdir_r(logroot.c_str(), S_IRWXU) == -1)  {
-            ESP_LOGE(TAG, "Can't create log folder");
-        }
-    }
-*/
     time_t rawtime;
     struct tm* timeinfo;
-    char buffer[30];
+    std::string fileNameDateNew;
+
+    std::string zwtime;
+    std::string ntpTime = "";
+
 
     time(&rawtime);
     timeinfo = localtime(&rawtime);
-
+    char buf[30];
-    strftime(buffer, 30, logfile.c_str(), timeinfo);
+    strftime(buf, sizeof(buf), logfile.c_str(), timeinfo);
-    std::string logpath = logroot + "/" + buffer; 
+    fileNameDateNew = std::string(buf);
 
     std::replace(message.begin(), message.end(), '\n', ' '); // Replace all newline characters
 
@@ -254,7 +190,75 @@ void ClassLogFile::WriteToFile(esp_log_level_t level, std::string tag, std::stri
     else {
         ESP_LOG_LEVEL(level, "", "%s", message.c_str());
     }
-    WriteToDedicatedFile(logpath, level, message, _time);
+    
+
+    if (level > loglevel) {// Only write to file if loglevel is below threshold
+        return;
+    }
+
+
+    if (_time)
+    {
+        char logLineDate[30];
+        strftime(logLineDate, sizeof(logLineDate), "%Y-%m-%dT%H:%M:%S", timeinfo);
+        ntpTime = std::string(logLineDate);
+    }
+
+    std::string loglevelString; 
+    switch(level) {
+        case  ESP_LOG_ERROR:
+            loglevelString = "ERR";
+            break;
+        case  ESP_LOG_WARN:
+            loglevelString = "WRN";
+            break;
+        case  ESP_LOG_INFO:
+            loglevelString = "INF";
+            break;
+        case  ESP_LOG_DEBUG:
+            loglevelString = "DBG";
+            break;
+        case  ESP_LOG_VERBOSE:
+            loglevelString = "VER";
+            break;
+        case  ESP_LOG_NONE:
+        default:
+            loglevelString = "NONE";
+            break;
+    }
+
+    std::string formatedUptime = getFormatedUptime(true);
+
+    std::string fullmessage = "[" + formatedUptime + "] "  + ntpTime + "\t<" + loglevelString + ">\t" + message + "\n";
+
+    if (fileNameDateNew != fileNameDate) { // Filename changed
+        // Make sure each day gets its own logfile
+        // Also we need to re-open it in case it needed to get closed for reading
+        std::string logpath = logroot + "/" + fileNameDateNew; 
+
+        ESP_LOGI(TAG, "Opening logfile %s for appending", logpath.c_str());
+        logFileAppendHande = fopen(logpath.c_str(), "a+");
+        if (logFileAppendHande==NULL) {
+            ESP_LOGE(TAG, "Can't open log file %s", logpath.c_str());
+            return;
+        }
+
+        fileNameDate = fileNameDateNew;
+    }
+  
+
+    fputs(fullmessage.c_str(), logFileAppendHande);
+    
+    fflush(logFileAppendHande);
+    fsync(fileno(logFileAppendHande));
+}
+
+
+void ClassLogFile::CloseLogFileAppendHandle() {
+
+    fclose(logFileAppendHande);
+    logFileAppendHande = NULL;
+    fileNameDate = "";
 }
 
 

code/components/jomjol_logfile/ClassLogFile.h

@@ -35,7 +35,7 @@ public:
     void WriteToFile(esp_log_level_t level, std::string tag, std::string message, bool _time);
     void WriteToFile(esp_log_level_t level, std::string tag, std::string message);
 
-    void WriteToDedicatedFile(std::string _fn, esp_log_level_t level, std::string message, bool _time = true);
+    void CloseLogFileAppendHandle();
 
     void CreateLogDirectories();
     void RemoveOldLogFile();

code/components/jomjol_tfliteclass/CTfLiteClass.cpp

@@ -237,7 +237,7 @@ unsigned char* CTfLiteClass::ReadFileToCharArray(std::string _fn)
 
   
 	  if(result != NULL) {
-        FILE* f = OpenFileAndWait(_fn.c_str(), "rb");     // previously only "r
+        FILE* f = fopen(_fn.c_str(), "rb");     // previously only "r
         fread(result, 1, size, f);
         fclose(f);        
 	  }else {

code/components/jomjol_wlan/read_wlanini.cpp

@@ -57,7 +57,7 @@ void LoadWlanFromFile(std::string fn, char *&_ssid, char *&_password, char *&_ho
     FILE* pFile;
     fn = FormatFileName(fn);
 
-    pFile = OpenFileAndWait(fn.c_str(), "r");
+    pFile = fopen(fn.c_str(), "r");
     ESP_LOGD(TAG, "file loaded");
 
     if (pFile == NULL)
@@ -199,7 +199,7 @@ bool ChangeHostName(std::string fn, std::string _newhostname)
 
     FILE* pFile;
     fn = FormatFileName(fn);
-    pFile = OpenFileAndWait(fn.c_str(), "r");
+    pFile = fopen(fn.c_str(), "r");
 
     ESP_LOGD(TAG, "file loaded\n");
 
@@ -241,7 +241,7 @@ bool ChangeHostName(std::string fn, std::string _newhostname)
 
     fclose(pFile);
 
-    pFile = OpenFileAndWait(fn.c_str(), "w+");
+    pFile = fopen(fn.c_str(), "w+");
 
     for (int i = 0; i < neuesfile.size(); ++i)
     {