Merge pull request #5012 from sakateka/fix-external-dir-fd-leaking

imfile: Fix leak of fd of external directories

plugins/imfile/imfile.c

@@ -852,10 +852,13 @@ detect_updates(fs_edge_t *const edge)
 				*  the old file in case a process is still writing into it until the FILE_DELETE_DELAY
 				*  is reached OR the inode has changed (see elseif below). In most cases, the
 				*  delay will never be reached and the file will be closed when the inode has changed.
+				*  Directories are deleted without delay.
 				*/
-				if (act->time_to_delete + FILE_DELETE_DELAY < ttNow) {
+				sbool is_file = act->edge->is_file;
-				DBGPRINTF("detect_updates obj gone away, unlinking: '%s', ttDelete: %lds, ttNow:%ld\n",
+				if (!is_file || act->time_to_delete + FILE_DELETE_DELAY < ttNow) {
-					act->name, ttNow - (act->time_to_delete + FILE_DELETE_DELAY), ttNow);
+				DBGPRINTF("detect_updates obj gone away, unlinking: "
+					"'%s', ttDelete: %lds, ttNow:%ld isFile: %d\n",
+					act->name, ttNow - (act->time_to_delete + FILE_DELETE_DELAY), ttNow, is_file);
 					act_obj_unlink(act);
 					restart = 1;
 				} else {
@@ -1038,9 +1041,9 @@ act_obj_destroy(act_obj_t *const act, const int is_deleted)
 		act_obj_t *target_act;
 		for(target_act = act->edge->active ; target_act != NULL ; target_act = target_act->next) {
 			if(target_act->source_name && !strcmp(target_act->source_name, act->name)) {
-				DBGPRINTF("act_obj_destroy: unlinking slink target %s of %s "
+				DBGPRINTF("act_obj_destroy: detect_updates for parent of target %s of %s symlink\n",
-						"symlink\n", target_act->name, act->name);
+						target_act->name, act->name);
-				act_obj_unlink(target_act);
+				detect_updates(target_act->edge->parent->root->edges);
 				break;
 			}
 		}

tests/Makefile.am

@@ -1573,6 +1573,7 @@ TESTS += \
 	imfile-rename.sh \
 	imfile-symlink.sh \
 	imfile-symlink-multi.sh \
+	imfile-symlink-ext-tmp-dir-tree.sh \
 	imfile-logrotate.sh \
 	imfile-logrotate-async.sh \
 	imfile-logrotate-multiple.sh \
@@ -2589,6 +2590,7 @@ EXTRA_DIST= \
 	imfile-rename.sh \
 	imfile-symlink.sh \
 	imfile-symlink-multi.sh \
+	imfile-symlink-ext-tmp-dir-tree.sh \
 	imfile-logrotate.sh \
 	imfile-logrotate-async.sh \
 	imfile-logrotate-copytruncate.sh \

tests/README

@@ -41,15 +41,19 @@ make check
 
 Running named tests
 ===================
-make testname.sh.log
+make testname.log
 
 For example, to run the imfile-basic.sh test, use
 
-make imfile-basic.sh.log
+    make imfile-basic.log
 
-Test output is in imfile-basic.sh.log
+Test output is in imfile-basic.log
 
-To re-run the test, first remove imfile-basic.sh.log then make again
+To re-run the test, first remove imfile-basic.log then make again
+
+Or an alternative option is to run
+
+    make check TESTS='imfile-basic.sh'
 
 * Using gdb to debug rsyslog during a test run
 

tests/diag.sh

@@ -893,6 +893,39 @@ check_journal_testmsg_received() {
 	fi;
 }
 
+# checks that among the open files found in /proc/<PID>/fd/*
+# there is or is not, depending on the calling mode,
+# a link with the specified suffix in the target name
+check_fd_for_pid() {
+  local pid="$1" mode="$2" suffix="$3" target seen
+  seen="false"
+  for fd in $(echo /proc/$pid/fd/*); do
+    target="$(readlink -m "$fd")"
+    if [[ "$target" != *$RSYSLOG_DYNNAME* ]]; then
+      continue
+    fi
+    if ((i % 10 == 0)); then
+      echo "INFO: check target='$target'"
+    fi
+    if [[ "$target" == *$suffix ]]; then
+      seen="true"
+      if [[ "$mode" == "exists" ]]; then
+        echo "PASS: check fd for pid=$pid mode='$mode' suffix='$suffix'"
+        return 0
+      fi
+    fi
+  done
+  if [[ "$seen" == "false" ]] && [[ "$mode" == "absent" ]]; then
+    echo "PASS: check fd for pid=$pid mode='$mode' suffix='$suffix'"
+    return 0
+  fi
+  echo "FAIL: check fd for pid=$pid mode='$mode' suffix='$suffix'"
+  if [[ "$mode" != "ignore" ]]; then
+    return 1
+  fi
+  return 0
+}
+
 # wait for main message queue to be empty. $1 is the instance.
 # we run in a loop to ensure rsyslog is *really* finished when a
 # function for the "finished predicate" is defined. This is done

tests/imfile-symlink-ext-tmp-dir-tree.sh

@@ -0,0 +1,80 @@
+#!/bin/bash
+# This test creates multiple symlinks (all watched by rsyslog via wildcard)
+# chained to target files via additional symlinks and checks that all files
+# are recorded with correct corresponding metadata (name of symlink
+# matching configuration).
+# This is part of the rsyslog testbench, released under ASL 2.0
+. "${srcdir:=.}"/diag.sh init
+. "$srcdir"/diag.sh check-inotify
+
+# #define FILE_DELETE_DELAY 5 /* how many seconds to wait before finally deleting a gone file */
+export RSYSLOG_DEBUG="debug nologfuncflow noprintmutexaction nostdout"
+export RSYSLOG_DEBUGLOG="log"
+export TEST_TIMEOUT=30
+
+# generate input files first. Note that rsyslog processes it as
+# soon as it start up (so the file should exist at that point).
+generate_conf
+add_conf '
+# comment out if you need more debug info:
+global( debug.whitelist="on" debug.files=["imfile.c"]
+  workDirectory="./'"$RSYSLOG_DYNNAME"'.work"
+)
+module(load="../plugins/imfile/.libs/imfile" mode="inotify")
+input(type="imfile" File="./'"$RSYSLOG_DYNNAME"'.links/*.log" Tag="file:"
+	Severity="error" Facility="local7" addMetadata="on")
+template(name="outfmt" type="list") {
+	constant(value="HEADER ")
+	property(name="msg" format="json")
+	constant(value=", filename: ")
+	property(name="$!metadata!filename")
+	constant(value=", fileoffset: ")
+	property(name="$!metadata!fileoffset")
+	constant(value="\n")
+}
+if $msg contains "msgnum:" then
+	action( type="omfile" file="'"$RSYSLOG_DYNNAME.out/$RSYSLOG_OUT_LOG"'" template="outfmt")
+'
+
+mkdir "$RSYSLOG_DYNNAME".links "$RSYSLOG_DYNNAME".work "$RSYSLOG_DYNNAME".out
+
+printf '\ncreating %s\n' "$RSYSLOG_DYNNAME".targets/container-1/logs/0.log
+mkdir -p "$RSYSLOG_DYNNAME".targets/container-1/logs
+./inputfilegen -m 1 >"$RSYSLOG_DYNNAME".targets/container-1/logs/0.log
+ls -l "$RSYSLOG_DYNNAME".targets/container-1/logs/0.log
+ln -sv "$PWD/$RSYSLOG_DYNNAME".targets/container-1/logs/0.log "$PWD/$RSYSLOG_DYNNAME".links/container-1.log
+printf '%s generated link %s\n' "$(tb_timestamp)" "container-1"
+ls -l "$RSYSLOG_DYNNAME".links/container-1.log
+
+# Start rsyslog now
+startup
+
+PID=$(cat "$RSYSLOG_PIDBASE".pid)
+echo "Rsyslog pid $RSYSLOG_PIDBASE.pid=$PID"
+if [[ "$PID" == "" ]]; then
+	error_exit 1
+fi
+
+echo "INFO: check files"
+# wait until this files has been opened
+check_fd_for_pid "$PID" exists "container-1/logs/0.log"
+check_fd_for_pid "$PID" exists "container-1/logs"
+
+echo "INFO: remove watched files"
+rm -vr "$RSYSLOG_DYNNAME".targets/container-1
+rm -v "$RSYSLOG_DYNNAME".links/container-1.log
+
+until check_fd_for_pid "$PID" absent "container-1/logs (deleted)"; do
+	if ((_wait_for_absent++ > TEST_TIMEOUT)); then
+		error_exit 1
+	fi
+	echo "INFO: trigger fd unlinking"
+	./inputfilegen -m 1 >"$RSYSLOG_DYNNAME".links/gogogo.log
+	./msleep 1000
+	rm -v "$RSYSLOG_DYNNAME".links/gogogo.log
+	./msleep 10
+done
+
+shutdown_when_empty
+wait_shutdown
+exit_test