Merge pull request #5193 from rgerhards/ci-reliable-hup

testbench: make waiting for HUP processing more reliable

dirty.h

@@ -5,7 +5,7 @@
  * yet a runtime library, because it depends on some functionality
  * residing somewhere else.
  *
- * Copyright 2007-2014 Rainer Gerhards and Adiscon GmbH.
+ * Copyright 2007-2023 Rainer Gerhards and Adiscon GmbH.
  *
  * This file is part of rsyslog.
  *
@@ -39,6 +39,7 @@ rsRetVal __attribute__((deprecated)) parseAndSubmitMessage(const uchar *hname,
 	const time_t ttGenTime, ruleset_t *pRuleset);
 rsRetVal createMainQueue(qqueue_t **ppQueue, uchar *pszQueueName, struct nvlst *lst);
 rsRetVal startMainQueue(rsconf_t *cnf, qqueue_t *pQueue);
+int get_bHadHUP(void);
 
 extern int MarkInterval;
 #define CONF_VERIFY_PARTIAL_CONF 0x02		/* bit: partial configuration to be checked */

plugins/imdiag/imdiag.c

@@ -5,7 +5,7 @@
  *
  * File begun on 2008-07-25 by RGerhards
  *
- * Copyright 2008-2020 Adiscon GmbH.
+ * Copyright 2008-2023 Adiscon GmbH.
  *
  * This file is part of rsyslog.
  *
@@ -375,6 +375,40 @@ awaitLookupTableReload(tcps_sess_t *pSess)
 	RETiRet;
 }
 
+static rsRetVal
+awaitHUPComplete(tcps_sess_t *pSess)
+{
+	const int max_tries = 10;
+	const int ms_to_sleep = 50;
+	const char *return_msg;
+	int b_saw_HUP = 0;
+	int tries = max_tries;
+	unsigned actual_tries = 0;
+	DEFiRet;
+
+	while(tries > 0) {
+		++actual_tries;
+		if(get_bHadHUP() == 1) {
+			tries = max_tries;
+			b_saw_HUP = 1;
+		} else {
+			--tries;
+		}
+		srSleep(0, ms_to_sleep * 50);
+	}
+
+	if(b_saw_HUP) {
+		return_msg = "seen HUP request, looks like it has completed";
+	} else {
+		return_msg = "timeout - looks like_HUP has completed";
+	}
+	CHKiRet(sendResponse(pSess, "%s [%d tries]\n", return_msg, actual_tries));
+	DBGPRINTF("imdiag: %s\n", return_msg);
+
+finalize_it:
+	RETiRet;
+}
+
 static rsRetVal
 enableDebug(tcps_sess_t *pSess)
 {
@@ -522,6 +556,8 @@ OnMsgReceived(tcps_sess_t *const pSess, uchar *const pRcv, const int iLenMsg)
 		CHKiRet(blockStatsReporting(pSess));
 	} else if(!ustrcmp(cmdBuf, UCHAR_CONSTANT("awaitstatsreport"))) {
 		CHKiRet(awaitStatsReport(pszMsg, pSess));
+	} else if(!ustrcmp(cmdBuf, UCHAR_CONSTANT("awaithupcomplete"))) {
+		CHKiRet(awaitHUPComplete(pSess));
 	} else if(!ustrcmp(cmdBuf, UCHAR_CONSTANT("enabledebug"))) {
 		CHKiRet(enableDebug(pSess));
 	} else {

tests/diag.sh

@@ -1019,6 +1019,19 @@ quit"
 }
 
 
+# wait for HUP to complete. $1 is the instance
+# note: there is a slight chance HUP was not completed. This can happen if it takes
+# the system very long (> 500ms) to receive the HUP and set the internal flag
+# variable. aka "very very low probability".
+await_HUP_processed() {
+	if [ "$1" == "2" ]; then
+		echo AwaitHUPComplete | $TESTTOOL_DIR/diagtalker -pIMDIAG_PORT2 || error_exit  $?
+	else
+		echo AwaitHUPComplete | $TESTTOOL_DIR/diagtalker -p$IMDIAG_PORT || error_exit  $?
+	fi
+}
+
+
 # wait for all pending lookup table reloads to complete $1 is the instance.
 await_lookup_table_reload() {
 	if [ "$1" == "2" ]; then
@@ -1203,8 +1216,10 @@ issue_HUP() {
 		sleeptime=1000
 	fi
 	kill -HUP $(cat $RSYSLOG_PIDBASE$1.pid)
-	printf 'HUP issued to pid %d\n' $(cat $RSYSLOG_PIDBASE$1.pid)
-	$TESTTOOL_DIR/msleep $sleeptime
+	printf 'HUP issued to pid %d - waiting for it to become processed\n' \
+		$(cat $RSYSLOG_PIDBASE$1.pid)
+	await_HUP_processed
+	#$TESTTOOL_DIR/msleep $sleeptime
 }
 
 

tools/rsyslogd.c

@@ -232,6 +232,22 @@ setsid(void)
 }
 #endif
 
+/* helper for imdiag. Returns if HUP processing has been requested or
+ * is not yet finished. We know this is racy, but imdiag handles this
+ * part by repeating operations. The mutex look is primarily to force
+ * a memory barrier, so that we have a change to see changes already
+ * written, but not present in the core's cache.
+ * 2023-07-26 Rainer Gerhards
+ */
+int
+get_bHadHUP(void)
+{
+	pthread_mutex_lock(&mutHadHUP);
+	const int ret = bHadHUP;
+	pthread_mutex_unlock(&mutHadHUP);
+	/* note: at this point ret can already be invalid */
+	return ret;
+}
 
 rsRetVal
 queryLocalHostname(void)
@@ -2074,10 +2090,12 @@ mainloop(void)
 		pthread_mutex_lock(&mutHadHUP);
 		need_free_mutex = 1;
 		if(bHadHUP) {
-			bHadHUP = 0;
 			need_free_mutex = 0;
 			pthread_mutex_unlock(&mutHadHUP);
 			doHUP();
+			pthread_mutex_lock(&mutHadHUP);
+			bHadHUP = 0;
+			pthread_mutex_unlock(&mutHadHUP);
 		}
 		if(need_free_mutex) {
 			pthread_mutex_unlock(&mutHadHUP);