filestore: avoid open write close sequence

Current file storing approach is using a open file, write data,
close file logic. If this technic is fixing the problem of getting
too much open files in Suricata it is not optimal.

Test on a loop shows that open, write, close on a single file is
two time slower than a single open, loop of write, close.

This patch updates the logic by storing the fd in the File structure.
This is done for a certain number of files. If this amount is exceeded
then the previous logic is used.

This patch also adds two counters. First is the number of
currently open files. The second one is the number of time
the open, write, close sequence has been used due to too much
open files.

In EVE, the entries are:
 stats {file_store: {"open_files_max_hit":0,"open_files":5}}

src/log-filestore.c

@@ -64,12 +64,21 @@
 
 static char g_logfile_base_dir[PATH_MAX] = "/tmp";
 
+SC_ATOMIC_DECLARE(uint32_t, filestore_open_file_cnt);  /**< Atomic counter of simultaneously open files */
+
 typedef struct LogFilestoreLogThread_ {
     LogFileCtx *file_ctx;
     /** LogFilestoreCtx has the pointer to the file and a mutex to allow multithreading */
     uint32_t file_cnt;
+    uint16_t counter_max_hits;
 } LogFilestoreLogThread;
 
+static uint64_t LogFilestoreOpenFilesCounter(void)
+{
+    uint64_t fcopy = SC_ATOMIC_GET(filestore_open_file_cnt);
+    return fcopy;
+}
+
 static void LogFilestoreMetaGetUri(FILE *fp, const Packet *p, const File *ff)
 {
     HtpState *htp_state = (HtpState *)p->flow->alstate;
@@ -182,6 +191,18 @@ static int FileWriteMeta(void)
     return g_file_write_meta;
 }
 
+static uint32_t g_file_store_max_open_files = 0;
+
+static void FileSetMaxOpenFiles(uint32_t count)
+{
+    g_file_store_max_open_files = count;
+}
+
+static uint32_t FileGetMaxOpenFiles(void)
+{
+    return g_file_store_max_open_files;
+}
+
 static void LogFilestoreLogCreateMetaFile(const Packet *p, const File *ff, char *filename, int ipver) {
     if (!FileWriteMeta())
         return;
@@ -321,7 +342,7 @@ static void LogFilestoreLogCloseMetaFile(const File *ff)
 }
 
 static int LogFilestoreLogger(ThreadVars *tv, void *thread_data, const Packet *p,
-        const File *ff, const uint8_t *data, uint32_t data_len, uint8_t flags)
+        File *ff, const uint8_t *data, uint32_t data_len, uint8_t flags)
 {
     SCEnter();
     LogFilestoreLogThread *aft = (LogFilestoreLogThread *)thread_data;
@@ -353,17 +374,34 @@ static int LogFilestoreLogger(ThreadVars *tv, void *thread_data, const Packet *p
         /* create a .meta file that contains time, src/dst/sp/dp/proto */
         LogFilestoreLogCreateMetaFile(p, ff, filename, ipver);
 
-        file_fd = open(filename, O_CREAT | O_TRUNC | O_NOFOLLOW | O_WRONLY, 0644);
-        if (file_fd == -1) {
-            SCLogDebug("failed to create file");
-            return -1;
+        if (SC_ATOMIC_GET(filestore_open_file_cnt) < FileGetMaxOpenFiles()) {
+            SC_ATOMIC_ADD(filestore_open_file_cnt, 1);
+            ff->fd = open(filename, O_CREAT | O_TRUNC | O_NOFOLLOW | O_WRONLY, 0644);
+            if (ff->fd == -1) {
+                SCLogDebug("failed to create file");
+                return -1;
+            }
+            file_fd = ff->fd;
+        } else {
+            file_fd = open(filename, O_CREAT | O_TRUNC | O_NOFOLLOW | O_WRONLY, 0644);
+            if (file_fd == -1) {
+                SCLogDebug("failed to create file");
+                return -1;
+            }
+            if (FileGetMaxOpenFiles() > 0) {
+                StatsIncr(tv, aft->counter_max_hits);
+            }
         }
     /* we can get called with a NULL ffd when we need to close */
     } else if (data != NULL) {
-        file_fd = open(filename, O_APPEND | O_NOFOLLOW | O_WRONLY);
-        if (file_fd == -1) {
-            SCLogDebug("failed to open file %s: %s", filename, strerror(errno));
-            return -1;
+        if (ff->fd == -1) {
+            file_fd = open(filename, O_APPEND | O_NOFOLLOW | O_WRONLY);
+            if (file_fd == -1) {
+                SCLogDebug("failed to open file %s: %s", filename, strerror(errno));
+                return -1;
+            }
+        } else {
+            file_fd = ff->fd;
         }
     }
 
@@ -371,11 +409,22 @@ static int LogFilestoreLogger(ThreadVars *tv, void *thread_data, const Packet *p
         ssize_t r = write(file_fd, (const void *)data, (size_t)data_len);
         if (r == -1) {
             SCLogDebug("write failed: %s", strerror(errno));
+            if (ff->fd != -1) {
+                SC_ATOMIC_SUB(filestore_open_file_cnt, 1);
+            }
+            ff->fd = -1;
+        }
+        if (ff->fd == -1) {
+            close(file_fd);
         }
-        close(file_fd);
     }
 
     if (flags & OUTPUT_FILEDATA_FLAG_CLOSE) {
+        if (ff->fd != -1) {
+            close(ff->fd);
+            ff->fd = -1;
+            SC_ATOMIC_SUB(filestore_open_file_cnt, 1);
+        }
         LogFilestoreLogCloseMetaFile(ff);
     }
 
@@ -418,6 +467,8 @@ static TmEcode LogFilestoreLogThreadInit(ThreadVars *t, const void *initdata, vo
 
     }
 
+    aft->counter_max_hits = StatsRegisterCounter("file_store.open_files_max_hit", t);
+
     *data = (void *)aft;
     return TM_ECODE_OK;
 }
@@ -528,9 +579,35 @@ static OutputCtx *LogFilestoreLogInitCtx(ConfNode *conf)
         }
     }
 
+    const char *file_count_str = ConfNodeLookupChildValue(conf, "max-open-files");
+    if (file_count_str != NULL) {
+        uint32_t file_count = 0;
+        if (ParseSizeStringU32(file_count_str,
+                               &file_count) < 0) {
+            SCLogError(SC_ERR_SIZE_PARSE, "Error parsing "
+                       "file-store.max-open-files "
+                       "from conf file - %s.  Killing engine",
+                       stream_depth_str);
+            exit(EXIT_FAILURE);
+        } else {
+            if (file_count != 0) {
+                FileSetMaxOpenFiles(file_count);
+                SCLogInfo("file-store will keep a max of %d simultaneously"
+                          " open files", file_count);
+            }
+        }
+    }
+
     SCReturnPtr(output_ctx, "OutputCtx");
 }
 
+
+void LogFilestoreInitConfig(void)
+{
+    StatsRegisterGlobalCounter("file_store.open_files", LogFilestoreOpenFilesCounter);
+}
+
+
 void LogFilestoreRegister (void)
 {
     OutputRegisterFiledataModule(LOGGER_FILE_STORE, MODULE_NAME, "file",
@@ -540,5 +617,7 @@ void LogFilestoreRegister (void)
         LogFilestoreLogInitCtx, LogFilestoreLogger, LogFilestoreLogThreadInit,
         LogFilestoreLogThreadDeinit, LogFilestoreLogExitPrintStats);
 
+    SC_ATOMIC_INIT(filestore_open_file_cnt);
+    SC_ATOMIC_SET(filestore_open_file_cnt, 0);
     SCLogDebug("registered");
 }

src/log-filestore.h

@@ -25,5 +25,6 @@
 #define __LOG_FILESTORE_H__
 
 void LogFilestoreRegister(void);
+void LogFilestoreInitConfig(void);
 
 #endif /* __LOG_FILELOG_H__ */

src/output-filedata.c

@@ -98,7 +98,7 @@ int OutputRegisterFiledataLogger(LoggerId id, const char *name,
 SC_ATOMIC_DECLARE(unsigned int, g_file_store_id);
 
 static int CallLoggers(ThreadVars *tv, OutputLoggerThreadStore *store_list,
-        Packet *p, const File *ff,
+        Packet *p, File *ff,
         const uint8_t *data, uint32_t data_len, uint8_t flags)
 {
     OutputFiledataLogger *logger = list;

src/output-filedata.h

@@ -34,7 +34,7 @@
 
 /** filedata logger function pointer type */
 typedef int (*FiledataLogger)(ThreadVars *, void *thread_data, const Packet *,
-        const File *, const uint8_t *, uint32_t, uint8_t);
+        File *, const uint8_t *, uint32_t, uint8_t);
 
 /** packet logger condition function pointer type,
  *  must return true for packets that should be logged

src/suricata.c

@@ -172,6 +172,7 @@
 #include "host-storage.h"
 
 #include "util-lua.h"
+#include "log-filestore.h"
 
 #ifdef HAVE_RUST
 #include "rust.h"
@@ -2218,6 +2219,7 @@ void PreRunInit(const int runmode)
     DefragInit();
     FlowInitConfig(FLOW_QUIET);
     IPPairInitConfig(FLOW_QUIET);
+    LogFilestoreInitConfig();
     StreamTcpInitConfig(STREAM_VERBOSE);
     AppLayerParserPostStreamSetup();
     AppLayerRegisterGlobalCounters();

src/util-file.c

@@ -776,6 +776,8 @@ File *FileOpenFile(FileContainer *ffc, const StreamingBufferConfig *sbcfg,
     ff->state = FILE_STATE_OPENED;
     SCLogDebug("flowfile state transitioned to FILE_STATE_OPENED");
 
+    ff->fd = -1;
+
     FileContainerAdd(ffc, ff);
 
     if (data != NULL) {

src/util-file.h

@@ -69,6 +69,8 @@ typedef struct File_ {
     uint32_t file_track_id;         /**< id used by protocol parser. Optional
                                      *   only used if FILE_USE_TRACKID flag set */
     uint32_t file_store_id;         /**< id used in store file name file.<id> */
+    int fd;                         /**< file descriptor for filestore, not
+                                        open if equal to -1 */
     uint8_t *name;
 #ifdef HAVE_MAGIC
     char *magic;

suricata.yaml.in

@@ -442,6 +442,10 @@ outputs:
       #waldo: file.waldo # waldo file to store the file_id across runs
       # uncomment to disable meta file writing
       #write-meta: no
+      # uncomment the following variable to define how many files can
+      # remain open for filestore by Suricata. Default value is 0 which
+      # means files get closed after each write
+      #max-open-files: 1000
 
   # output module to log files tracked in a easily parsable json format
   - file-log: