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}}

diff --git a/src/log-filestore.c b/src/log-filestore.c
index 90e6cd7f465fa7e560e1aa296f5a91d773d225e2..8777b4a60fdc98733118b98efbe1bdefeff6bc2c 100644 (file)
--- a/src/log-filestore.c
+++ b/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");
 }

diff --git a/src/log-filestore.h b/src/log-filestore.h
index d477506fc590338a370a1cf4e84582fc91404fc4..07b8da96b226e316047be83c584dfc5b3431c69b 100644 (file)
--- a/src/log-filestore.h
+++ b/src/log-filestore.h
@@ -25,5 +25,6 @@
 #define __LOG_FILESTORE_H__
 
 void LogFilestoreRegister(void);
+void LogFilestoreInitConfig(void);
 
 #endif /* __LOG_FILELOG_H__ */

diff --git a/src/output-filedata.c b/src/output-filedata.c
index 3964de86c22a46eb2e7d3bb5bc06eeccf4591171..224ab7adc0640a273a4a2e43c8cf730054df7930 100644 (file)
--- a/src/output-filedata.c
+++ b/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;

diff --git a/src/output-filedata.h b/src/output-filedata.h
index 4c661b2de1cc8b1fc7de71482d880bcbdeb3ac9b..8a280b67529d86e006bfe358bd1bf66058ff0a7b 100644 (file)
--- a/src/output-filedata.h
+++ b/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

diff --git a/src/suricata.c b/src/suricata.c
index ee5499faa0e83a1bd8d3382a38ce4e9941105380..1ec7f1c6b477e0f789030dacfed6bef4ded4b078 100644 (file)
--- a/src/suricata.c
+++ b/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();

diff --git a/src/util-file.c b/src/util-file.c
index 86dd8df2674cb056d01551ba38bc97d88dbce584..c7ee27e45a2b1b4c507d186c0a9abea989639fb8 100644 (file)
--- a/src/util-file.c
+++ b/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) {

diff --git a/src/util-file.h b/src/util-file.h
index 4c52adae1d2c958230d0e4b404205c4598a942de..6d6ae9e75db1b2927af330251a316b95043acf69 100644 (file)
--- a/src/util-file.h
+++ b/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;

diff --git a/suricata.yaml.in b/suricata.yaml.in
index d0462f70797a6472dd37df7a13c3f1105aafc9a7..c7a4ea8be3f9a7dbe20e5e9c702b1540c8a2c534 100644 (file)
--- a/suricata.yaml.in
+++ b/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: