From 6fcc0ca9f9bedfa6eaafbad81a3c84bf55794110 Mon Sep 17 00:00:00 2001
From: Stephan Bosch <stephan@rename-it.nl>
Date: Wed, 22 Apr 2015 21:36:29 +0200
Subject: [PATCH] LDA Sieve plugin: Changed error handling so that each action
 log message can have up-to-date time stamps. This change matches a change in
 LDA that is aimed at logging timing statistics.

---
 src/lib-sieve/plugins/enotify/cmd-notify.c |  2 +-
 src/lib-sieve/sieve-result.c               | 61 +++-----------
 src/lib-sieve/sieve-result.h               | 15 ++--
 src/lib-sieve/sieve-types.h                |  3 -
 src/lib-sieve/sieve.c                      | 64 +++++++-------
 src/lib-sieve/sieve.h                      | 18 ++--
 src/plugins/lda-sieve/Makefile.am          |  2 +
 src/plugins/lda-sieve/lda-sieve-log.c      | 97 ++++++++++++++++++++++
 src/plugins/lda-sieve/lda-sieve-log.h      | 11 +++
 src/plugins/lda-sieve/lda-sieve-plugin.c   | 52 ++++++++----
 src/sieve-tools/sieve-filter.c             | 10 ++-
 src/sieve-tools/sieve-test.c               | 31 ++++---
 src/testsuite/testsuite-result.c           |  7 +-
 src/testsuite/testsuite-script.c           |  4 +-
 14 files changed, 241 insertions(+), 136 deletions(-)
 create mode 100644 src/plugins/lda-sieve/lda-sieve-log.c
 create mode 100644 src/plugins/lda-sieve/lda-sieve-log.h

diff --git a/src/lib-sieve/plugins/enotify/cmd-notify.c b/src/lib-sieve/plugins/enotify/cmd-notify.c
index 4e47699a7..b3b7d1bd8 100644
--- a/src/lib-sieve/plugins/enotify/cmd-notify.c
+++ b/src/lib-sieve/plugins/enotify/cmd-notify.c
@@ -523,7 +523,7 @@ static int act_notify_check_duplicate
 	nenv.svinst = renv->svinst;
 	nenv.method = nact->method;
 	nenv.ehandler = sieve_prefix_ehandler_create
-		(sieve_result_get_error_handler(renv->result), act->location, "notify");
+		(renv->ehandler, act->location, "notify");
 
 	result = nmth_def->action_check_duplicates(&nenv, nact, nact_other);
 
diff --git a/src/lib-sieve/sieve-result.c b/src/lib-sieve/sieve-result.c
index 1f71fbda1..2543f7848 100644
--- a/src/lib-sieve/sieve-result.c
+++ b/src/lib-sieve/sieve-result.c
@@ -25,12 +25,6 @@
 
 #include <stdio.h>
 
-/*
- * Defaults
- */
-
-#define DEFAULT_ACTION_LOG_FORMAT "msgid=%m: %$"
-
 /*
  * Types
  */
@@ -79,8 +73,6 @@ struct sieve_result {
 	/* Context data for extensions */
 	ARRAY(void *) ext_contexts;
 
-	struct sieve_error_handler *ehandler;
-
 	struct sieve_action_exec_env action_env;
 
 	struct sieve_action keep_action;
@@ -100,7 +92,7 @@ struct sieve_result {
 
 struct sieve_result *sieve_result_create
 (struct sieve_instance *svinst, const struct sieve_message_data *msgdata,
-	const struct sieve_script_env *senv, struct sieve_error_handler *ehandler)
+	const struct sieve_script_env *senv)
 {
 	pool_t pool;
 	struct sieve_result *result;
@@ -113,10 +105,6 @@ struct sieve_result *sieve_result_create
 
 	p_array_init(&result->ext_contexts, pool, 4);
 
-	if ( ehandler != NULL )
-		sieve_error_handler_ref(ehandler);
-	result->ehandler = ehandler;
-
 	result->action_env.svinst = svinst;
 	result->action_env.result = result;
 	result->action_env.scriptenv = senv;
@@ -153,9 +141,6 @@ void sieve_result_unref(struct sieve_result **result)
 	if ( hash_table_is_created((*result)->action_contexts) )
         hash_table_destroy(&(*result)->action_contexts);
 
-	if ( (*result)->ehandler != NULL )
-		sieve_error_handler_unref(&(*result)->ehandler);
-
 	if ( (*result)->action_env.ehandler != NULL )
 		sieve_error_handler_unref(&(*result)->action_env.ehandler);
 
@@ -173,11 +158,6 @@ pool_t sieve_result_pool(struct sieve_result *result)
  * Getters/Setters
  */
 
-struct sieve_error_handler *sieve_result_get_error_handler
-(struct sieve_result *result)
-{
-	return result->ehandler;
-}
 const struct sieve_script_env *sieve_result_get_script_env
 (struct sieve_result *result)
 {
@@ -196,16 +176,6 @@ struct sieve_message_context *sieve_result_get_message_context
 	return result->action_env.msgctx;
 }
 
-void sieve_result_set_error_handler
-(struct sieve_result *result, struct sieve_error_handler *ehandler)
-{
-	if ( result->ehandler != ehandler ) {
-		sieve_error_handler_ref(ehandler);
-		sieve_error_handler_unref(&result->ehandler);
-		result->ehandler = ehandler;
-	}
-}
-
 /*
  * Extension support
  */
@@ -939,27 +909,15 @@ bool sieve_result_print
  * Result execution
  */
 
-static void _sieve_result_prepare_execution(struct sieve_result *result)
+static void _sieve_result_prepare_execution(struct sieve_result *result,
+	struct sieve_error_handler *ehandler)
 {
-	const struct sieve_message_data *msgdata = result->action_env.msgdata;
 	const struct sieve_script_env *senv = result->action_env.scriptenv;
-	const struct var_expand_table *tab;
 
-	tab = mail_deliver_get_log_var_expand_table(msgdata->mail, NULL);
+	result->action_env.ehandler = ehandler;
 	result->action_env.exec_status =
 		( senv->exec_status == NULL ?
 			t_new(struct sieve_exec_status, 1) : senv->exec_status );
-
-	if ( result->action_env.ehandler != NULL )
-		sieve_error_handler_unref(&result->action_env.ehandler);
-
-	if ( senv->action_log_format != NULL ) {
-		result->action_env.ehandler = sieve_varexpand_ehandler_create
-			(result->ehandler, senv->action_log_format, tab);
-	} else {
-		result->action_env.ehandler = sieve_varexpand_ehandler_create
-            (result->ehandler, DEFAULT_ACTION_LOG_FORMAT, tab);
-	}
 }
 
 static int _sieve_result_implicit_keep
@@ -1072,9 +1030,10 @@ static int _sieve_result_implicit_keep
 }
 
 int sieve_result_implicit_keep
-(struct sieve_result *result)
+(struct sieve_result *result,
+	struct sieve_error_handler *ehandler)
 {
-	_sieve_result_prepare_execution(result);
+	_sieve_result_prepare_execution(result, ehandler);
 
 	return _sieve_result_implicit_keep(result, TRUE);
 }
@@ -1357,7 +1316,8 @@ static void sieve_result_transaction_finish
 }
 
 int sieve_result_execute
-(struct sieve_result *result, bool *keep)
+(struct sieve_result *result, bool *keep,
+	struct sieve_error_handler *ehandler)
 {
 	int status = SIEVE_EXEC_OK, result_status;
 	struct sieve_result_action *first_action, *last_action;
@@ -1368,7 +1328,7 @@ int sieve_result_execute
 
 	/* Prepare environment */
 
-	_sieve_result_prepare_execution(result);
+	_sieve_result_prepare_execution(result, ehandler);
 
 	/* Make notice of this attempt */
 
@@ -1424,6 +1384,7 @@ int sieve_result_execute
 	sieve_result_transaction_finish
 		(result, first_action, status);
 
+	result->action_env.ehandler = NULL;
 	return result_status;
 }
 
diff --git a/src/lib-sieve/sieve-result.h b/src/lib-sieve/sieve-result.h
index 869870a03..9763b95c3 100644
--- a/src/lib-sieve/sieve-result.h
+++ b/src/lib-sieve/sieve-result.h
@@ -21,8 +21,7 @@ struct sieve_result;
 
 struct sieve_result *sieve_result_create
 	(struct sieve_instance *svinst, const struct sieve_message_data *msgdata,
-		const struct sieve_script_env *senv,
-		struct sieve_error_handler *ehandler);
+		const struct sieve_script_env *senv);
 
 void sieve_result_ref(struct sieve_result *result);
 
@@ -34,11 +33,6 @@ pool_t sieve_result_pool(struct sieve_result *result);
  * Getters/Setters
  */
 
-struct sieve_error_handler *sieve_result_get_error_handler
-	(struct sieve_result *result);
-void sieve_result_set_error_handler
-	(struct sieve_result *result, struct sieve_error_handler *ehandler);
-
 const struct sieve_script_env *sieve_result_get_script_env
 	(struct sieve_result *result);
 const struct sieve_message_data *sieve_result_get_message_data
@@ -148,11 +142,14 @@ void sieve_result_set_failure_action
  * Result execution
  */
 
-int sieve_result_implicit_keep(struct sieve_result *result);
+int sieve_result_implicit_keep(struct sieve_result *result,
+	struct sieve_error_handler *ehandler);
 
 void sieve_result_mark_executed(struct sieve_result *result);
 
-int sieve_result_execute(struct sieve_result *result, bool *keep);
+int sieve_result_execute
+	(struct sieve_result *result, bool *keep,
+		struct sieve_error_handler *ehandler);
 
 bool sieve_result_executed(struct sieve_result *result);
 
diff --git a/src/lib-sieve/sieve-types.h b/src/lib-sieve/sieve-types.h
index 0b6b803c1..bfb375ec9 100644
--- a/src/lib-sieve/sieve-types.h
+++ b/src/lib-sieve/sieve-types.h
@@ -173,9 +173,6 @@ struct sieve_trace_config {
  */
 
 struct sieve_script_env {
-	/* Logging related */
-	const char *action_log_format;
-
 	/* Mail-related */
 	struct mail_user *user;
 	const char *default_mailbox;
diff --git a/src/lib-sieve/sieve.c b/src/lib-sieve/sieve.c
index b5003e396..c78175fda 100644
--- a/src/lib-sieve/sieve.c
+++ b/src/lib-sieve/sieve.c
@@ -333,11 +333,9 @@ static int sieve_run
 		memset(senv->exec_status, 0, sizeof(*senv->exec_status));
 
 	/* Create result object */
-	if ( *result == NULL )
+	if ( *result == NULL ) {
 		*result = sieve_result_create
-			(sieve_binary_svinst(sbin), msgdata, senv, ehandler);
-	else {
-		sieve_result_set_error_handler(*result, ehandler);
+			(sieve_binary_svinst(sbin), msgdata, senv);
 	}
 
 	/* Run the interpreter */
@@ -539,7 +537,9 @@ int sieve_test
 
 int sieve_execute
 (struct sieve_binary *sbin, const struct sieve_message_data *msgdata,
-	const struct sieve_script_env *senv, struct sieve_error_handler *ehandler,
+	const struct sieve_script_env *senv,
+	struct sieve_error_handler *exec_ehandler,
+	struct sieve_error_handler *action_ehandler,
 	enum sieve_runtime_flags flags, bool *keep)
 {
 	struct sieve_result *result = NULL;
@@ -548,7 +548,7 @@ int sieve_execute
 	if ( keep != NULL ) *keep = FALSE;
 
 	/* Run the script */
-	ret = sieve_run(sbin, &result, msgdata, senv, ehandler, flags);
+	ret = sieve_run(sbin, &result, msgdata, senv, exec_ehandler, flags);
 
 	/* Evaluate status and execute the result:
 	 *   Strange situations, e.g. currupt binaries, must be handled by the caller.
@@ -557,10 +557,11 @@ int sieve_execute
 	 */
 	if ( ret > 0 ) {
 		/* Execute result */
-		ret = sieve_result_execute(result, keep);
+		ret = sieve_result_execute(result, keep, action_ehandler);
 	} else if ( ret == SIEVE_EXEC_FAILURE ) {
 		/* Perform implicit keep if script failed with a normal runtime error */
-		switch ( sieve_result_implicit_keep(result) ) {
+		switch ( sieve_result_implicit_keep
+			(result, action_ehandler) ) {
 		case SIEVE_EXEC_OK:
 			if ( keep != NULL ) *keep = TRUE;
 			break;
@@ -604,7 +605,7 @@ struct sieve_multiscript *sieve_multiscript_start_execute
 	struct sieve_result *result;
 	struct sieve_multiscript *mscript;
 
-	result = sieve_result_create(svinst, msgdata, senv, NULL);
+	result = sieve_result_create(svinst, msgdata, senv);
 	pool = sieve_result_pool(result);
 
 	sieve_result_set_keep_action(result, NULL, NULL);
@@ -634,11 +635,8 @@ struct sieve_multiscript *sieve_multiscript_start_test
 }
 
 static void sieve_multiscript_test
-(struct sieve_multiscript *mscript, struct sieve_error_handler *ehandler,
-	bool *keep)
+(struct sieve_multiscript *mscript, bool *keep)
 {
-	sieve_result_set_error_handler(mscript->result, ehandler);
-
 	if ( mscript->status > 0 ) {
 		mscript->status = sieve_result_print
 			(mscript->result, mscript->scriptenv, mscript->teststream, keep);
@@ -653,12 +651,10 @@ static void sieve_multiscript_execute
 (struct sieve_multiscript *mscript, struct sieve_error_handler *ehandler,
 	bool *keep)
 {
-	sieve_result_set_error_handler(mscript->result, ehandler);
-
 	if ( mscript->status > 0 ) {
-		mscript->status = sieve_result_execute(mscript->result, keep);
+		mscript->status = sieve_result_execute(mscript->result, keep, ehandler);
 	} else {
-		if ( !sieve_result_implicit_keep(mscript->result) )
+		if ( !sieve_result_implicit_keep(mscript->result, ehandler) )
 			mscript->status = SIEVE_EXEC_KEEP_FAILED;
 		else
 			if ( keep != NULL ) *keep = TRUE;
@@ -667,8 +663,9 @@ static void sieve_multiscript_execute
 
 bool sieve_multiscript_run
 (struct sieve_multiscript *mscript, struct sieve_binary *sbin,
-	struct sieve_error_handler *ehandler, enum sieve_runtime_flags flags,
-	bool final)
+	struct sieve_error_handler *exec_ehandler,
+	struct sieve_error_handler *action_ehandler,
+	enum sieve_runtime_flags flags, bool final)
 {
 	if ( !mscript->active ) return FALSE;
 
@@ -677,16 +674,17 @@ bool sieve_multiscript_run
 
 	/* Run the script */
 	mscript->status = sieve_run(sbin, &mscript->result, mscript->msgdata,
-		mscript->scriptenv, ehandler, flags);
+		mscript->scriptenv, exec_ehandler, flags);
 
 	if ( mscript->status >= 0 ) {
 		mscript->keep = FALSE;
 
-		if ( mscript->teststream != NULL )
-			sieve_multiscript_test(mscript, ehandler, &mscript->keep);
-		else
-			sieve_multiscript_execute(mscript, ehandler, &mscript->keep);
-
+		if ( mscript->teststream != NULL ) {
+			sieve_multiscript_test(mscript, &mscript->keep);
+		} else {
+			sieve_multiscript_execute
+				(mscript, action_ehandler, &mscript->keep);
+		}
 		mscript->active =
 			( mscript->active && mscript->keep && !final && mscript->status > 0 );
 	}
@@ -703,14 +701,11 @@ int sieve_multiscript_status(struct sieve_multiscript *mscript)
 }
 
 int sieve_multiscript_tempfail(struct sieve_multiscript **mscript,
-	struct sieve_error_handler *ehandler)
+	struct sieve_error_handler *action_ehandler)
 {
 	struct sieve_result *result = (*mscript)->result;
 	int ret = (*mscript)->status;
 
-	if ( ehandler != NULL )
-		sieve_result_set_error_handler(result, ehandler);
-
 	if ( (*mscript)->active ) {
 		ret = SIEVE_EXEC_TEMP_FAILURE;
 
@@ -718,7 +713,8 @@ int sieve_multiscript_tempfail(struct sieve_multiscript **mscript,
 			/* Part of the result is already executed, need to fall back to
 			 * to implicit keep (FIXME)
 			 */
-			switch ( sieve_result_implicit_keep(result) ) {
+			switch ( sieve_result_implicit_keep
+				(result, action_ehandler) ) {
 			case SIEVE_EXEC_OK:
 				ret = SIEVE_EXEC_FAILURE;
 				break;
@@ -736,21 +732,19 @@ int sieve_multiscript_tempfail(struct sieve_multiscript **mscript,
 }
 
 int sieve_multiscript_finish(struct sieve_multiscript **mscript,
-	struct sieve_error_handler *ehandler, bool *keep)
+	struct sieve_error_handler *action_ehandler, bool *keep)
 {
 	struct sieve_result *result = (*mscript)->result;
 	int ret = (*mscript)->status;
 
-	if ( ehandler != NULL )
-		sieve_result_set_error_handler(result, ehandler);
-
 	if ( (*mscript)->active ) {
 		ret = SIEVE_EXEC_FAILURE;
 
 		if ( (*mscript)->teststream ) {
 			(*mscript)->keep = TRUE;
 		} else {
-			switch ( sieve_result_implicit_keep(result) ) {
+			switch ( sieve_result_implicit_keep
+				(result, action_ehandler) ) {
 			case SIEVE_EXEC_OK:
 				(*mscript)->keep = TRUE;
 				break;
diff --git a/src/lib-sieve/sieve.h b/src/lib-sieve/sieve.h
index 0f78dd297..3cd10ae24 100644
--- a/src/lib-sieve/sieve.h
+++ b/src/lib-sieve/sieve.h
@@ -170,7 +170,9 @@ int sieve_test
  */
 int sieve_execute
 	(struct sieve_binary *sbin, const struct sieve_message_data *msgdata,
-		const struct sieve_script_env *senv, struct sieve_error_handler *ehandler,
+		const struct sieve_script_env *senv,
+		struct sieve_error_handler *exec_ehandler,
+		struct sieve_error_handler *action_ehandler,
 		enum sieve_runtime_flags flags, bool *keep);
 
 /*
@@ -188,16 +190,18 @@ struct sieve_multiscript *sieve_multiscript_start_test
 
 bool sieve_multiscript_run
 	(struct sieve_multiscript *mscript, struct sieve_binary *sbin,
-		struct sieve_error_handler *ehandler, enum sieve_runtime_flags flags,
-		bool final);
+		struct sieve_error_handler *exec_ehandler,
+		struct sieve_error_handler *action_ehandler,
+		enum sieve_runtime_flags flags, bool final);
 
 int sieve_multiscript_status(struct sieve_multiscript *mscript);
 
-int sieve_multiscript_tempfail(struct sieve_multiscript **mscript,
-	struct sieve_error_handler *ehandler);
+int sieve_multiscript_tempfail
+	(struct sieve_multiscript **mscript,
+		struct sieve_error_handler *action_ehandler);
 int sieve_multiscript_finish
-	(struct sieve_multiscript **mscript, struct sieve_error_handler *ehandler,
-		bool *keep);
+	(struct sieve_multiscript **mscript,
+		struct sieve_error_handler *action_ehandler, bool *keep);
 
 /*
  * Configured limits
diff --git a/src/plugins/lda-sieve/Makefile.am b/src/plugins/lda-sieve/Makefile.am
index 191141608..39ed1af01 100644
--- a/src/plugins/lda-sieve/Makefile.am
+++ b/src/plugins/lda-sieve/Makefile.am
@@ -12,7 +12,9 @@ lib90_sieve_plugin_la_LIBADD = \
 	$(top_builddir)/src/lib-sieve/libdovecot-sieve.la
 
 lib90_sieve_plugin_la_SOURCES = \
+	lda-sieve-log.c \
 	lda-sieve-plugin.c
 
 noinst_HEADERS = \
+	lda-sieve-log.h \
 	lda-sieve-plugin.h
diff --git a/src/plugins/lda-sieve/lda-sieve-log.c b/src/plugins/lda-sieve/lda-sieve-log.c
new file mode 100644
index 000000000..8a62b9c35
--- /dev/null
+++ b/src/plugins/lda-sieve/lda-sieve-log.c
@@ -0,0 +1,97 @@
+/* Copyright (c) 2002-2015 Pigeonhole authors, see the included COPYING file
+ */
+
+#include "lib.h"
+#include "str.h"
+#include "var-expand.h"
+#include "lda-settings.h"
+#include "mail-deliver.h"
+
+#include "sieve-error-private.h"
+
+#include "lda-sieve-log.h"
+
+struct lda_sieve_log_ehandler {
+	struct sieve_error_handler handler;
+
+	struct mail_deliver_context *mdctx;
+};
+
+static const char *ATTR_FORMAT(2, 0) lda_sieve_log_expand_message
+(struct sieve_error_handler *_ehandler,
+	const char *fmt, va_list args)
+{
+	struct lda_sieve_log_ehandler *ehandler =
+		(struct lda_sieve_log_ehandler *) _ehandler;
+	struct mail_deliver_context *mdctx = ehandler->mdctx;
+	const struct var_expand_table *table;
+	string_t *str;
+
+	table = mail_deliver_ctx_get_log_var_expand_table
+		(mdctx, t_strdup_vprintf(fmt, args));
+
+	str = t_str_new(256);
+	var_expand(str, mdctx->set->deliver_log_format, table);
+	return str_c(str);
+}
+
+static void ATTR_FORMAT(4, 0) lda_sieve_log_verror
+(struct sieve_error_handler *ehandler, unsigned int flags,
+	const char *location, const char *fmt, va_list args)
+{
+	sieve_direct_error(ehandler->svinst,
+		ehandler->parent, flags, location, "%s",
+		lda_sieve_log_expand_message(ehandler, fmt, args));
+}
+
+static void ATTR_FORMAT(4, 0) lda_sieve_log_vwarning
+(struct sieve_error_handler *ehandler, unsigned int flags,
+	const char *location, const char *fmt, va_list args)
+{
+	sieve_direct_warning(ehandler->svinst,
+		ehandler->parent, flags, location, "%s",
+		lda_sieve_log_expand_message(ehandler, fmt, args));
+}
+
+static void ATTR_FORMAT(4, 0) lda_sieve_log_vinfo
+(struct sieve_error_handler *ehandler, unsigned int flags,
+	const char *location, const char *fmt, va_list args)
+{
+	sieve_direct_info(ehandler->svinst,
+		ehandler->parent, flags, location, "%s",
+		lda_sieve_log_expand_message(ehandler, fmt, args));
+}
+
+static void ATTR_FORMAT(4, 0) lda_sieve_log_vdebug
+(struct sieve_error_handler *ehandler, unsigned int flags,
+	const char *location, const char *fmt, va_list args)
+{
+	sieve_direct_debug(ehandler->svinst,
+		ehandler->parent, flags, location, "%s",
+		lda_sieve_log_expand_message(ehandler, fmt, args));
+}
+
+struct sieve_error_handler *lda_sieve_log_ehandler_create
+(struct sieve_error_handler *parent,
+	struct mail_deliver_context *mdctx)
+{
+	struct lda_sieve_log_ehandler *ehandler;
+	pool_t pool;
+
+	if ( parent == NULL )
+		return NULL;
+
+	pool = pool_alloconly_create("lda_sieve_log_ehandler", 2048);
+	ehandler = p_new(pool, struct lda_sieve_log_ehandler, 1);
+	sieve_error_handler_init_from_parent(&ehandler->handler, pool, parent);
+
+	ehandler->mdctx = mdctx;
+
+	ehandler->handler.verror = lda_sieve_log_verror;
+	ehandler->handler.vwarning = lda_sieve_log_vwarning;
+	ehandler->handler.vinfo = lda_sieve_log_vinfo;
+	ehandler->handler.vdebug = lda_sieve_log_vdebug;
+
+	return &(ehandler->handler);
+}
+
diff --git a/src/plugins/lda-sieve/lda-sieve-log.h b/src/plugins/lda-sieve/lda-sieve-log.h
new file mode 100644
index 000000000..2758b885b
--- /dev/null
+++ b/src/plugins/lda-sieve/lda-sieve-log.h
@@ -0,0 +1,11 @@
+/* Copyright (c) 2002-2015 Pigeonhole authors, see the included COPYING file
+ */
+
+#ifndef __LDA_SIEVE_LOG_H
+#define __LDA_SIEVE_LOG_H
+
+struct sieve_error_handler *lda_sieve_log_ehandler_create
+	(struct sieve_error_handler *parent,
+		struct mail_deliver_context *mdctx);
+
+#endif /* __LDA_SIEVE_LOG_H */
diff --git a/src/plugins/lda-sieve/lda-sieve-plugin.c b/src/plugins/lda-sieve/lda-sieve-plugin.c
index 1187a40f1..fe208f546 100644
--- a/src/plugins/lda-sieve/lda-sieve-plugin.c
+++ b/src/plugins/lda-sieve/lda-sieve-plugin.c
@@ -17,6 +17,7 @@
 #include "sieve-script.h"
 #include "sieve-storage.h"
 
+#include "lda-sieve-log.h"
 #include "lda-sieve-plugin.h"
 
 #include <stdlib.h>
@@ -168,6 +169,7 @@ struct lda_sieve_run_context {
 
 	struct sieve_error_handler *user_ehandler;
 	struct sieve_error_handler *master_ehandler;
+	struct sieve_error_handler *action_ehandler;
 	const char *userlog;
 };
 
@@ -455,9 +457,10 @@ static int lda_sieve_singlescript_execute
 (struct lda_sieve_run_context *srctx)
 {
 	struct sieve_instance *svinst = srctx->svinst;
+	struct mail_deliver_context *mdctx = srctx->mdctx;
 	struct sieve_script *script = srctx->scripts[0];
 	bool user_script = ( script == srctx->user_script );
-	struct sieve_error_handler *ehandler;
+	struct sieve_error_handler *exec_ehandler, *action_ehandler;
 	struct sieve_binary *sbin;
 	bool debug = srctx->mdctx->dest_user->mail_debug;
 	enum sieve_compile_flags cpflags = 0;
@@ -468,9 +471,9 @@ static int lda_sieve_singlescript_execute
 	if ( user_script ) {
 		cpflags |= SIEVE_COMPILE_FLAG_NOGLOBAL;
 		rtflags |= SIEVE_RUNTIME_FLAG_NOGLOBAL;
-		ehandler = srctx->user_ehandler;
+		exec_ehandler = srctx->user_ehandler;
 	} else {
-		ehandler = srctx->master_ehandler;
+		exec_ehandler = srctx->master_ehandler;
 	}
 
 	/* Open the script */
@@ -495,8 +498,11 @@ static int lda_sieve_singlescript_execute
 			"Executing script from `%s'", sieve_get_source(sbin));
 	}
 
-	ret = sieve_execute
-		(sbin, srctx->msgdata, srctx->scriptenv, ehandler, rtflags, NULL);
+	action_ehandler = lda_sieve_log_ehandler_create
+		(exec_ehandler, mdctx);
+	ret = sieve_execute(sbin, srctx->msgdata, srctx->scriptenv,
+		exec_ehandler, action_ehandler, rtflags, NULL);
+	sieve_error_handler_unref(&action_ehandler);
 
 	/* Recompile if corrupt binary */
 
@@ -527,8 +533,11 @@ static int lda_sieve_singlescript_execute
 				(svinst, "Executing script from `%s'", sieve_get_source(sbin));
 		}
 
-		ret = sieve_execute
-			(sbin, srctx->msgdata, srctx->scriptenv, ehandler, rtflags, NULL);
+		action_ehandler = lda_sieve_log_ehandler_create
+			(exec_ehandler, mdctx);
+		ret = sieve_execute(sbin, srctx->msgdata, srctx->scriptenv,
+			exec_ehandler, action_ehandler, rtflags, NULL);
+		sieve_error_handler_unref(&action_ehandler);
 
 		/* Save new version */
 
@@ -546,10 +555,11 @@ static int lda_sieve_multiscript_execute
 (struct lda_sieve_run_context *srctx)
 {
 	struct sieve_instance *svinst = srctx->svinst;
+	struct mail_deliver_context *mdctx = srctx->mdctx;
 	struct sieve_script *const *scripts = srctx->scripts;
 	unsigned int count = srctx->script_count;
 	struct sieve_multiscript *mscript;
-	struct sieve_error_handler *ehandler = srctx->master_ehandler;
+	struct sieve_error_handler *exec_ehandler, *action_ehandler;
 	bool debug = srctx->mdctx->dest_user->mail_debug;
 	struct sieve_script *last_script = NULL;
 	bool user_script = FALSE, more = TRUE, compile_error = FALSE;
@@ -564,6 +574,7 @@ static int lda_sieve_multiscript_execute
 
 	/* Execute scripts */
 
+	exec_ehandler = srctx->master_ehandler;
 	for ( i = 0; i < count && more; i++ ) {
 		struct sieve_binary *sbin = NULL;
 		struct sieve_script *script = scripts[i];
@@ -577,9 +588,9 @@ static int lda_sieve_multiscript_execute
 		if ( user_script ) {
 			cpflags |= SIEVE_COMPILE_FLAG_NOGLOBAL;
 			rtflags |= SIEVE_RUNTIME_FLAG_NOGLOBAL;
-			ehandler = srctx->user_ehandler;
+			exec_ehandler = srctx->user_ehandler;
 		} else {
-			ehandler = srctx->master_ehandler;
+			exec_ehandler = srctx->master_ehandler;
 		}
 
 		/* Open */
@@ -603,9 +614,14 @@ static int lda_sieve_multiscript_execute
 				(svinst, "Executing script from `%s'", sieve_get_source(sbin));
 		}
 
-		more = sieve_multiscript_run(mscript, sbin, ehandler, rtflags, final);
+		action_ehandler = lda_sieve_log_ehandler_create
+			(exec_ehandler, mdctx);
+		more = sieve_multiscript_run(mscript, sbin,
+			exec_ehandler, action_ehandler, rtflags, final);
+		sieve_error_handler_unref(&action_ehandler);
 
 		if ( !more ) {
+			sieve_error_handler_unref(&action_ehandler);
 			if ( sieve_multiscript_status(mscript) == SIEVE_EXEC_BIN_CORRUPT &&
 				sieve_is_loaded(sbin) ) {
 				/* Close corrupt script */
@@ -622,7 +638,11 @@ static int lda_sieve_multiscript_execute
 
 				/* Execute again */
 
-				more = sieve_multiscript_run(mscript, sbin, ehandler, rtflags, final);
+				action_ehandler = lda_sieve_log_ehandler_create
+					(exec_ehandler, mdctx);
+				more = sieve_multiscript_run(mscript, sbin,
+					exec_ehandler, action_ehandler, rtflags, final);
+				sieve_error_handler_unref(&action_ehandler);
 
 				/* Save new version */
 
@@ -637,10 +657,13 @@ static int lda_sieve_multiscript_execute
 	}
 
 	/* Finish execution */
+	action_ehandler = lda_sieve_log_ehandler_create
+		(exec_ehandler, mdctx);
 	if ( compile_error && error == SIEVE_ERROR_TEMP_FAILURE )
-		ret = sieve_multiscript_tempfail(&mscript, ehandler);
+		ret = sieve_multiscript_tempfail(&mscript, action_ehandler);
 	else
-		ret = sieve_multiscript_finish(&mscript, ehandler, NULL);
+		ret = sieve_multiscript_finish(&mscript, action_ehandler, NULL);
+	sieve_error_handler_unref(&action_ehandler);
 
 	/* Don't log additional messages about compile failure */
 	if ( compile_error && ret == SIEVE_EXEC_FAILURE ) {
@@ -909,7 +932,6 @@ static int lda_sieve_execute
 		memset(&scriptenv, 0, sizeof(scriptenv));
 		memset(&estatus, 0, sizeof(estatus));
 
-		scriptenv.action_log_format = mdctx->set->deliver_log_format;
 		scriptenv.default_mailbox = mdctx->dest_mailbox_name;
 		scriptenv.mailbox_autocreate = mdctx->set->lda_mailbox_autocreate;
 		scriptenv.mailbox_autosubscribe = mdctx->set->lda_mailbox_autosubscribe;
diff --git a/src/sieve-tools/sieve-filter.c b/src/sieve-tools/sieve-filter.c
index a49d4e142..8e0f4e063 100644
--- a/src/sieve-tools/sieve-filter.c
+++ b/src/sieve-tools/sieve-filter.c
@@ -118,11 +118,19 @@ static int filter_message
 
 	/* Execute script */
 	if ( execute ) {
+		struct sieve_error_handler *action_ehandler;
+
 		sieve_info(ehandler, NULL,
 			"filtering: [%s; %"PRIuUOFF_T" bytes] `%s'", date, size,
 			str_sanitize(subject, 40));
 
-		ret = sieve_execute(sbin, &msgdata, senv, ehandler, 0, NULL);
+		action_ehandler = sieve_prefix_ehandler_create
+			(ehandler, NULL, t_strdup_printf("msgid=%s",
+				( msgdata.id == NULL ? "unspecified" : msgdata.id )));
+		ret = sieve_execute(sbin, &msgdata, senv,
+				ehandler, action_ehandler, 0, NULL);
+		sieve_error_handler_unref(&action_ehandler);
+
 	} else {
 		(void)o_stream_send_str(sfctx->teststream,
 			t_strdup_printf(">> Filtering message:\n\n"
diff --git a/src/sieve-tools/sieve-test.c b/src/sieve-tools/sieve-test.c
index 09a08715b..23c738721 100644
--- a/src/sieve-tools/sieve-test.c
+++ b/src/sieve-tools/sieve-test.c
@@ -131,7 +131,7 @@ int main(int argc, char **argv)
 	struct sieve_message_data msgdata;
 	struct sieve_script_env scriptenv;
 	struct sieve_exec_status estatus;
-	struct sieve_error_handler *ehandler;
+	struct sieve_error_handler *ehandler, *action_ehandler;
 	struct ostream *teststream = NULL;
 	struct ostream *tracestream = NULL;
 	bool force_compile = FALSE, execute = FALSE;
@@ -278,8 +278,14 @@ int main(int argc, char **argv)
 
 		/* Create streams for test and trace output */
 
-		if ( !execute )
+		if ( !execute ) {
+			action_ehandler = NULL;
 			teststream = o_stream_create_fd(1, 0, FALSE);
+		} else {
+			action_ehandler = sieve_prefix_ehandler_create
+				(ehandler, NULL, t_strdup_printf("msgid=%s",
+					( msgdata.id == NULL ? "unspecified" : msgdata.id )));
+		}
 
 		if ( tracefile != NULL )
 			tracestream = sieve_tool_open_output_stream(tracefile);
@@ -307,12 +313,13 @@ int main(int argc, char **argv)
 			main_sbin = NULL;
 
 			/* Execute/Test script */
-			if ( execute )
-				ret = sieve_execute
-					(sbin, &msgdata, &scriptenv, ehandler, 0, NULL);
-			else
-				ret = sieve_test
-					(sbin, &msgdata, &scriptenv, ehandler, teststream, 0, NULL);
+			if ( execute ) {
+				ret = sieve_execute(sbin, &msgdata, &scriptenv,
+					ehandler, action_ehandler, 0, NULL);
+			} else {
+				ret = sieve_test(sbin, &msgdata, &scriptenv,
+					ehandler, teststream, 0, NULL);
+			}
 		} else {
 			/* Multiple scripts */
 			const char *const *sfiles;
@@ -354,7 +361,8 @@ int main(int argc, char **argv)
 				}
 
 				/* Execute/Test script */
-				more = sieve_multiscript_run(mscript, sbin, ehandler, 0, FALSE);
+				more = sieve_multiscript_run(mscript, sbin,
+					ehandler, action_ehandler, 0, FALSE);
 			}
 
 			/* Execute/Test main script */
@@ -370,7 +378,8 @@ int main(int argc, char **argv)
 				sbin = main_sbin;
 				main_sbin = NULL;
 
-				sieve_multiscript_run(mscript, sbin, ehandler, 0, TRUE);
+				sieve_multiscript_run(mscript, sbin,
+					ehandler, ehandler, 0, TRUE);
 			}
 
 			result = sieve_multiscript_finish(&mscript, ehandler, NULL);
@@ -411,6 +420,8 @@ int main(int argc, char **argv)
 	}
 
 	/* Cleanup error handler */
+	if (action_ehandler != NULL)
+		sieve_error_handler_unref(&action_ehandler);
 	sieve_error_handler_unref(&ehandler);
 
 	sieve_tool_deinit(&sieve_tool);
diff --git a/src/testsuite/testsuite-result.c b/src/testsuite/testsuite-result.c
index b2babfca7..6b7a4a607 100644
--- a/src/testsuite/testsuite-result.c
+++ b/src/testsuite/testsuite-result.c
@@ -25,7 +25,7 @@ void testsuite_result_init(void)
 	struct sieve_instance *svinst = testsuite_sieve_instance;
 
 	_testsuite_result = sieve_result_create
-		(svinst, &testsuite_msgdata, testsuite_scriptenv, testsuite_log_ehandler);
+		(svinst, &testsuite_msgdata, testsuite_scriptenv);
 }
 
 void testsuite_result_deinit(void)
@@ -45,7 +45,7 @@ void testsuite_result_reset
 	}
 
 	_testsuite_result = sieve_result_create
-		(svinst, &testsuite_msgdata, testsuite_scriptenv, testsuite_log_ehandler);
+		(svinst, &testsuite_msgdata, testsuite_scriptenv);
 	sieve_interpreter_set_result(renv->interp, _testsuite_result);
 }
 
@@ -75,7 +75,8 @@ bool testsuite_result_execute(const struct sieve_runtime_env *renv)
 	testsuite_log_clear_messages();
 
 	/* Execute the result */
-	ret=sieve_result_execute(_testsuite_result, NULL);
+	ret=sieve_result_execute
+		(_testsuite_result, NULL, testsuite_log_ehandler);
 
 	return ( ret > 0 );
 }
diff --git a/src/testsuite/testsuite-script.c b/src/testsuite/testsuite-script.c
index a5fedc2bc..0054c9961 100644
--- a/src/testsuite/testsuite-script.c
+++ b/src/testsuite/testsuite-script.c
@@ -215,8 +215,8 @@ bool testsuite_script_multiscript
 
 		sieve_runtime_trace(renv, SIEVE_TRLVL_TESTS, "run script `%s'", script);
 
-		more = sieve_multiscript_run
-			(mscript, sbin, testsuite_log_ehandler, 0, final);
+		more = sieve_multiscript_run(mscript, sbin,
+			testsuite_log_ehandler, testsuite_log_ehandler, 0, final);
 
 		sieve_close(&sbin);
 	}
-- 
GitLab