From a5f3a29c6e80cab123053626131774bfb8c70e03 Mon Sep 17 00:00:00 2001
From: Stephan Bosch <stephan@rename-it.nl>
Date: Wed, 21 Jul 2010 17:43:16 +0200
Subject: [PATCH] Further developed new runtime trace debugging; test suite is
 also now included.

---
 Makefile.am                                   |  2 +-
 doc/man/sieve-test.1                          | 31 ++++----
 src/lib-sieve-tool/sieve-tool.c               | 74 +++++++++++++++----
 src/lib-sieve-tool/sieve-tool.h               | 13 ++++
 .../plugins/spamvirustest/tst-spamvirustest.c | 10 ++-
 src/lib-sieve/sieve-code.c                    |  2 -
 src/lib-sieve/sieve-match.c                   |  5 +-
 src/lib-sieve/sieve-runtime-trace.c           |  6 ++
 src/lib-sieve/sieve-runtime-trace.h           | 14 +++-
 src/sieve-tools/sieve-test.c                  | 70 ++++++------------
 src/testsuite/cmd-test-config.c               |  6 +-
 src/testsuite/cmd-test-mailbox.c              |  7 +-
 src/testsuite/cmd-test-message.c              |  8 +-
 src/testsuite/cmd-test.c                      |  2 +
 src/testsuite/testsuite.c                     | 29 +++++---
 src/testsuite/tst-test-error.c                |  8 +-
 src/testsuite/tst-test-multiscript.c          |  4 +-
 src/testsuite/tst-test-result-execute.c       |  2 +-
 18 files changed, 181 insertions(+), 112 deletions(-)

diff --git a/Makefile.am b/Makefile.am
index fc1f3913f..299053392 100644
--- a/Makefile.am
+++ b/Makefile.am
@@ -24,7 +24,7 @@ endif
 
 # Testsuite tests
 
-TESTSUITE_BIN = $(top_builddir)/src/testsuite/testsuite
+TESTSUITE_BIN = $(top_builddir)/src/testsuite/testsuite $(TESTSUITE_OPTIONS)
 
 if TESTSUITE_VALGRIND
 TEST_BIN = valgrind -q --error-exitcode=1 --show-reachable=yes --leak-check=full $(TESTSUITE_BIN) 
diff --git a/doc/man/sieve-test.1 b/doc/man/sieve-test.1
index 4da259539..c2dc20987 100644
--- a/doc/man/sieve-test.1
+++ b/doc/man/sieve-test.1
@@ -91,9 +91,14 @@ Specify additional scripts to be executed before the main script. Multiple \fB\-
 allowed and the specified scripts are executed sequentially in the order specified at the command
 line.
 .TP
-\fB\-t\fP \fItrace\-option\fP
-Configure runtime trace debugging. Trace debugging provides detailed insight in the operations performed
-by the Sieve script. Refer to the trace debugging section below. 
+\fB\-t\fP \fItrace\-file\fP
+Enables runtime trace debugging. Trace debugging provides detailed insight in the operations performed
+by the Sieve script. Refer to the runtime trace debugging section below. The trace information is
+written to the specified file. Using '\-' as filename causes the trace data to be written to \fBstdout\fP.
+.TP
+\fB\-T\fP \fItrace\-option\fP
+Configures runtime trace debugging, which is enabled with the \fP\-t\fP option. Refer to the runtime
+trace debugging section below.  
 .TP
 \fB\-x\fP "\fIextension extension ...\fP"
 Set the available extensions. The parameter is a space\-separated list of the active extensions. By
@@ -108,21 +113,19 @@ extensions that are available by default, except for the enotify extension.
 
 .SH RUNTIME TRACE DEBUGGING
 .PP
-Using the \fB-t\fP option, the \fBsieve\-test\fP tool can be configured to print detailed information on
-the Sieve script execution. For example, the encountered commands, the performed tests and the matched 
-values can be printed. 
+Using the \fB-t\fP option, the \fBsieve\-test\fP tool can be configured to print detailed trace information
+on the Sieve script execution to a file or standard output. For example, the encountered commands, the
+performed tests and the matched values can be printed. 
 .PP
-The \fB\-t\fP option can be specified multiple times. It can be used as follows:
+The runtime trace can be configured using the \fB\-T\fP option, which can be specified multiple times. 
+It can be used as follows:
 
 .TP 2
-\fB\-tlevel=...\fP
+\fB\-Tlevel=...\fP
 Set the verbosity level of the trace debugging. One of the following values can be supplied:
 .RS 2
 .TP 3 
-\fInone\fP (default)
-No trace debugging.
-.TP 
-\fIactions\fP
+\fIactions\fP (default)
 Only print executed action commands, like keep, fileinto, reject and redirect.
 .TP
 \fIcommands\fP
@@ -135,10 +138,10 @@ Print all commands and performed tests.
 Print all commands, performed tests and the values matched for those tests. 
 .RE
 .TP 2
-\fB\-tdebug\fP
+\fB\-Tdebug\fP
 Print debug messages as well. This is usually only useful for developers and produces messy output.
 .TP
-\fB\-taddresses\fP
+\fB\-Taddresses\fP
 Print byte code addresses for the current trace output. Normally, only the current Sieve source code 
 position is printed. The byte code addresses are equal to those listed in a binary dump produced
 using the \fB\-d\fP option or by the \fBsieved(1)\fP command.
diff --git a/src/lib-sieve-tool/sieve-tool.c b/src/lib-sieve-tool/sieve-tool.c
index c4f317376..fe4e2f187 100644
--- a/src/lib-sieve-tool/sieve-tool.c
+++ b/src/lib-sieve-tool/sieve-tool.c
@@ -442,6 +442,28 @@ void sieve_tool_get_envelope_data
 		*sender = "sender@example.com";
 }
 
+/*
+ * File I/O
+ */
+
+struct ostream *sieve_tool_open_output_stream(const char *filename)
+{
+	struct ostream *outstream;
+	int fd;
+
+	if ( strcmp(filename, "-") == 0 ) 
+		outstream = o_stream_create_fd(1, 0, TRUE);
+	else {
+		if ( (fd = open(filename, O_WRONLY | O_TRUNC | O_CREAT, 0600)) < 0 ) {
+			i_fatal("failed to open file for writing: %m");
+		}
+		
+		outstream = o_stream_create_fd(fd, 0, TRUE);
+	}
+	
+	return outstream;
+}
+
 /*
  * Sieve script handling
  */
@@ -481,32 +503,52 @@ struct sieve_binary *sieve_tool_script_open
 		
 	return sbin;
 }
-	
+
 void sieve_tool_dump_binary_to(struct sieve_binary *sbin, const char *filename)	
 {
-	int dfd = -1;
 	struct ostream *dumpstream;
-	
+
 	if ( filename == NULL ) return;
-	
-	if ( strcmp(filename, "-") == 0 ) 
-		dumpstream = o_stream_create_fd(1, 0, FALSE);
-	else {
-		if ( (dfd = open(filename, O_WRONLY | O_TRUNC | O_CREAT, 0600)) < 0 ) {
-			i_fatal("failed to open dump-file for writing: %m");
-		}
-		
-		dumpstream = o_stream_create_fd(dfd, 0, FALSE);
-	}
-	
+
+	dumpstream = sieve_tool_open_output_stream(filename);
 	if ( dumpstream != NULL ) {
 		(void) sieve_dump(sbin, dumpstream, FALSE);
 		o_stream_destroy(&dumpstream);
 	} else {
 		i_fatal("Failed to create stream for sieve code dump.");
 	}
+}
 	
-	if ( dfd != -1 )
-		close(dfd);
+/*
+ * Commandline option parsing
+ */
+
+void sieve_tool_parse_trace_option
+(struct sieve_trace_config *tr_config, const char *tr_option)
+{
+    if ( strncmp(tr_option, "level=", 6) == 0 ) {
+        const char *lvl = &tr_option[6];
+
+        if ( strcmp(lvl, "none") == 0 ) {
+            tr_config->level = SIEVE_TRLVL_NONE;
+        } else if ( strcmp(lvl, "actions") == 0 ) {
+            tr_config->level = SIEVE_TRLVL_ACTIONS;
+        } else if ( strcmp(lvl, "commands") == 0 ) {
+            tr_config->level = SIEVE_TRLVL_COMMANDS;
+        } else if ( strcmp(lvl, "tests") == 0 ) {
+            tr_config->level = SIEVE_TRLVL_TESTS;
+        } else if ( strcmp(lvl, "matching") == 0 ) {
+            tr_config->level = SIEVE_TRLVL_MATCHING;
+        } else {
+            i_fatal_status(EX_USAGE, "Unknown -tlevel= trace level: %s", lvl);
+        }
+    } else if ( strcmp(tr_option, "debug") == 0 ) {
+        tr_config->flags |= SIEVE_TRFLG_DEBUG;
+    } else if ( strcmp(tr_option, "addresses") == 0 ) {
+        tr_config->flags |= SIEVE_TRFLG_ADDRESSES;
+    } else {
+        i_fatal_status(EX_USAGE, "Unknown -t trace option value: %s", tr_option);
+    }
 }
 
+
diff --git a/src/lib-sieve-tool/sieve-tool.h b/src/lib-sieve-tool/sieve-tool.h
index 0222d80c8..948334a32 100644
--- a/src/lib-sieve-tool/sieve-tool.h
+++ b/src/lib-sieve-tool/sieve-tool.h
@@ -72,6 +72,12 @@ void sieve_tool_set_setting_callback
 void sieve_tool_get_envelope_data
 	(struct mail *mail, const char **recipient, const char **sender);
 
+/*
+ * File I/O
+ */
+
+struct ostream *sieve_tool_open_output_stream(const char *filename);
+
 /*
  * Sieve script handling
  */
@@ -83,4 +89,11 @@ struct sieve_binary *sieve_tool_script_open
 void sieve_tool_dump_binary_to
 	(struct sieve_binary *sbin, const char *filename);
 
+/*
+ * Command line option parsing
+ */
+
+void sieve_tool_parse_trace_option
+	(struct sieve_trace_config *tr_config, const char *tr_option);
+
 #endif /* __SIEVE_TOOL_H */
diff --git a/src/lib-sieve/plugins/spamvirustest/tst-spamvirustest.c b/src/lib-sieve/plugins/spamvirustest/tst-spamvirustest.c
index c195eb52f..a93b5d224 100644
--- a/src/lib-sieve/plugins/spamvirustest/tst-spamvirustest.c
+++ b/src/lib-sieve/plugins/spamvirustest/tst-spamvirustest.c
@@ -279,8 +279,14 @@ static int tst_spamvirustest_operation_execute
 			
 	/* Perform test */
 
-	sieve_runtime_trace
-		(renv, SIEVE_TRLVL_TESTS, "%s test", sieve_operation_mnemonic(op));
+	if ( sieve_operation_is(op, spamtest_operation) ) {
+		sieve_runtime_trace
+			(renv, SIEVE_TRLVL_TESTS, "spamtest test [percent=%s]",
+				( percent ? "true" : "false" ));
+	} else {
+		sieve_runtime_trace
+			(renv, SIEVE_TRLVL_TESTS, "virustest test");
+	}
 
 	/* Initialize match */
 	mctx = sieve_match_begin(renv, &mcht, &cmp, NULL, key_value); 	
diff --git a/src/lib-sieve/sieve-code.c b/src/lib-sieve/sieve-code.c
index 02cb48415..bccc4caa1 100644
--- a/src/lib-sieve/sieve-code.c
+++ b/src/lib-sieve/sieve-code.c
@@ -1048,8 +1048,6 @@ static bool opc_jmp_dump
 static int opc_jmp_execute
 (const struct sieve_runtime_env *renv, sieve_size_t *address ATTR_UNUSED) 
 {
-	sieve_runtime_trace(renv, SIEVE_TRLVL_COMMANDS, "jump");
-	
 	return sieve_interpreter_program_jump(renv->interp, TRUE);
 }	
 		
diff --git a/src/lib-sieve/sieve-match.c b/src/lib-sieve/sieve-match.c
index 0d4c8bb93..19e5c7520 100644
--- a/src/lib-sieve/sieve-match.c
+++ b/src/lib-sieve/sieve-match.c
@@ -147,7 +147,10 @@ int sieve_match_end(struct sieve_match_context **mctx)
 	pool_unref(&(*mctx)->pool);
 	*mctx = NULL;
 
-	if ( ret < 0 ) status = ret;
+	if ( ret < 0 || status < 0 )
+		status = ( ret <= status ? ret : status );
+	else
+		status = status || ret;
 
 	sieve_runtime_trace(renv, SIEVE_TRLVL_MATCHING,
 		"  finishing match with result: %s", 
diff --git a/src/lib-sieve/sieve-runtime-trace.c b/src/lib-sieve/sieve-runtime-trace.c
index a4bdd8426..7a29b8445 100644
--- a/src/lib-sieve/sieve-runtime-trace.c
+++ b/src/lib-sieve/sieve-runtime-trace.c
@@ -138,3 +138,9 @@ void _sieve_runtime_trace_end(const struct sieve_runtime_env *renv)
 		"## Finished executing script '%s'", script_name);
 	_trace_line_print_empty(renv);
 }
+
+void _sieve_runtime_trace_sep(const struct sieve_runtime_env *renv)
+{
+	_trace_line_print_empty(renv);	
+}
+
diff --git a/src/lib-sieve/sieve-runtime-trace.h b/src/lib-sieve/sieve-runtime-trace.h
index 8aa895327..00c4a2c47 100644
--- a/src/lib-sieve/sieve-runtime-trace.h
+++ b/src/lib-sieve/sieve-runtime-trace.h
@@ -125,21 +125,27 @@ static inline void sieve_runtime_trace_here
 
 void _sieve_runtime_trace_begin(const struct sieve_runtime_env *renv);
 void _sieve_runtime_trace_end(const struct sieve_runtime_env *renv);
+void _sieve_runtime_trace_sep(const struct sieve_runtime_env *renv);
 
 static inline void sieve_runtime_trace_begin
 (const struct sieve_runtime_env *renv)
 {
-	if ( renv->trace_stream != NULL && 
-		renv->trace_config.level > SIEVE_TRLVL_NONE )
+	if ( renv->trace_stream != NULL )
 		_sieve_runtime_trace_begin(renv);
 }
 
 static inline void sieve_runtime_trace_end
 (const struct sieve_runtime_env *renv)
 {
-	if ( renv->trace_stream != NULL && 
-		renv->trace_config.level > SIEVE_TRLVL_NONE )
+	if ( renv->trace_stream != NULL )
 		_sieve_runtime_trace_end(renv);
 }
 
+static inline void sieve_runtime_trace_sep
+(const struct sieve_runtime_env *renv)
+{
+	if ( renv->trace_stream != NULL )
+		_sieve_runtime_trace_sep(renv);
+}
+
 #endif /* __SIEVE_TRACE_H */
diff --git a/src/sieve-tools/sieve-test.c b/src/sieve-tools/sieve-test.c
index 55c05771e..b71fbec6b 100644
--- a/src/sieve-tools/sieve-test.c
+++ b/src/sieve-tools/sieve-test.c
@@ -47,7 +47,8 @@ static void print_help(void)
 "Usage: sieve-test [-C] [-d <dump-filename>] [-e] [-f <envelope-sender>]\n"
 "                  [-l <mail-location>] [-m <default-mailbox>]\n" 
 "                  [-r <recipient-address>] [-s <script-file>]\n"
-"                  [-t <trace-option>] [-P <plugin>] [-x <extensions>]\n"
+"                  [-t <trace-filename>] [-T <trace-option>]\n"
+"                  [-P <plugin>] [-x <extensions>]\n"
 "                  <script-file> <mail-file>\n"
 	);
 }
@@ -96,38 +97,6 @@ static void duplicate_mark
 	i_info("marked duplicate for user %s.\n", user);
 }
 
-/*
- * Trace option handling
- */
-
-static void parse_trace_option
-(struct sieve_trace_config *tr_config, const char *tr_option)
-{
-	if ( strncmp(tr_option, "level=", 6) == 0 ) {
-		const char *lvl = &tr_option[6];
-		
-		if ( strcmp(lvl, "none") == 0 ) {
-			tr_config->level = SIEVE_TRLVL_NONE;
-		} else if ( strcmp(lvl, "actions") == 0 ) {
-			tr_config->level = SIEVE_TRLVL_ACTIONS;
-		} else if ( strcmp(lvl, "commands") == 0 ) {
-			tr_config->level = SIEVE_TRLVL_COMMANDS;
-		} else if ( strcmp(lvl, "tests") == 0 ) {
-			tr_config->level = SIEVE_TRLVL_TESTS;
-		} else if ( strcmp(lvl, "matching") == 0 ) {
-			tr_config->level = SIEVE_TRLVL_MATCHING;
-		} else {
-			i_fatal_status(EX_USAGE, "Unknown -tlevel= trace level: %s", lvl);
-		}
-	} else if ( strcmp(tr_option, "debug") == 0 ) {
-		tr_config->flags |= SIEVE_TRFLG_DEBUG;
-	} else if ( strcmp(tr_option, "addresses") == 0 ) {
-		tr_config->flags |= SIEVE_TRFLG_ADDRESSES;
-	} else {
-		i_fatal_status(EX_USAGE, "Unknown -t trace option value: %s", tr_option);
-	}
-}
-
 /*
  * Tool implementation
  */
@@ -136,8 +105,8 @@ int main(int argc, char **argv)
 {
 	struct sieve_instance *svinst;
 	ARRAY_TYPE (const_string) scriptfiles;
-	const char *scriptfile, *recipient, *sender, *mailbox, *dumpfile, *mailfile, 
-		*mailloc; 
+	const char *scriptfile, *recipient, *sender, *mailbox, *dumpfile, *tracefile,
+		*mailfile, *mailloc; 
 	struct sieve_trace_config tr_config;
 	struct mail *mail;
 	struct sieve_binary *main_sbin, *sbin = NULL;
@@ -146,19 +115,21 @@ int main(int argc, char **argv)
 	struct sieve_exec_status estatus;
 	struct sieve_error_handler *ehandler;
 	struct ostream *teststream = NULL;
+	struct ostream *tracestream = NULL;
 	bool force_compile = FALSE, execute = FALSE;
-	bool trace = FALSE;
 	int exit_status = EXIT_SUCCESS;
 	int ret, c;
 
 	sieve_tool = sieve_tool_init
-		("sieve-test", &argc, &argv, "r:f:m:d:l:s:eCt:DP:x:u:", FALSE);
+		("sieve-test", &argc, &argv, "r:f:m:d:l:s:eCt:T:DP:x:u:", FALSE);
 
 	t_array_init(&scriptfiles, 16);
 	
 	/* Parse arguments */
-	scriptfile = recipient = sender = mailbox = dumpfile = mailfile = mailloc = NULL;
+	scriptfile = recipient = sender = mailbox = dumpfile = tracefile =
+		mailfile = mailloc = NULL;
 	memset(&tr_config, 0, sizeof(tr_config));
+	tr_config.level = SIEVE_TRLVL_ACTIONS;
 	while ((c = sieve_tool_getopt(sieve_tool)) > 0) {
 		switch (c) {
 		case 'r':
@@ -173,16 +144,16 @@ int main(int argc, char **argv)
 			/* default mailbox (keep box) */
 			mailbox = optarg;
 			break;
-		case 'd':
-			/* dump file */
-			dumpfile = optarg;
-			break;
 		case 'l':
 			/* mail location */
 			mailloc = optarg;
 			break;
 		case 't':
-			parse_trace_option(&tr_config, optarg);
+			/* trace file */
+			tracefile = optarg;
+			break;
+		case 'T':
+			sieve_tool_parse_trace_option(&tr_config, optarg);
 			break;
 		case 's': 
 			/* scriptfile executed before main script */
@@ -272,9 +243,13 @@ int main(int argc, char **argv)
 		msgdata.auth_user = sieve_tool_get_username(sieve_tool);
 		(void)mail_get_first_header(mail, "Message-ID", &msgdata.id);
 
-		/* Create stream for test and trace output */
-		if ( !execute || trace )
-			teststream = o_stream_create_fd(1, 0, FALSE);	
+		/* Create streams for test and trace output */
+
+		if ( !execute )
+			teststream = o_stream_create_fd(1, 0, FALSE);
+
+		if ( tracefile != NULL )
+			tracestream = sieve_tool_open_output_stream(tracefile);
 		
 		/* Compose script environment */
 		memset(&scriptenv, 0, sizeof(scriptenv));
@@ -287,8 +262,7 @@ int main(int argc, char **argv)
 		scriptenv.smtp_close = sieve_smtp_close;
 		scriptenv.duplicate_mark = duplicate_mark;
 		scriptenv.duplicate_check = duplicate_check;
-		scriptenv.trace_stream = 
-			( tr_config.level > SIEVE_TRLVL_NONE ? teststream : NULL );
+		scriptenv.trace_stream = teststream;
 		scriptenv.trace_config = tr_config;
 		scriptenv.exec_status = &estatus;
 	
diff --git a/src/testsuite/cmd-test-config.c b/src/testsuite/cmd-test-config.c
index 23afc7c9d..5082bc9b9 100644
--- a/src/testsuite/cmd-test-config.c
+++ b/src/testsuite/cmd-test-config.c
@@ -336,7 +336,7 @@ static int cmd_test_config_set_operation_execute
 	 */
 		
 	sieve_runtime_trace(renv, SIEVE_TRLVL_COMMANDS,
-		"TEST_CONFIG_SET %s = '%s'", str_c(setting), str_c(value));
+		"test_config :set %s = `%s'", str_c(setting), str_c(value));
 
 	testsuite_setting_set(str_c(setting), str_c(value));
 
@@ -361,7 +361,7 @@ static int cmd_test_config_unset_operation_execute
 	 */
 		
 	sieve_runtime_trace(renv, SIEVE_TRLVL_COMMANDS,
-		"TEST_CONFIG_UNSET %s", str_c(setting));
+		"test_config :unset `%s'", str_c(setting));
 
 	testsuite_setting_unset(str_c(setting));
 
@@ -387,7 +387,7 @@ static int cmd_test_config_reload_operation_execute
 	 */
 		
 	sieve_runtime_trace(renv, SIEVE_TRLVL_COMMANDS,
-		"TEST_CONFIG_RELOAD [%s]", str_c(extension));
+		"test_config :reload `%s'", str_c(extension));
 
 	ext = sieve_extension_get_by_name(renv->svinst, str_c(extension));
 	if ( ext == NULL ) {
diff --git a/src/testsuite/cmd-test-mailbox.c b/src/testsuite/cmd-test-mailbox.c
index 53e97d4bf..ce6db518f 100644
--- a/src/testsuite/cmd-test-mailbox.c
+++ b/src/testsuite/cmd-test-mailbox.c
@@ -237,11 +237,12 @@ static int cmd_test_mailbox_operation_execute
 	 * Perform operation
 	 */
 		
-	sieve_runtime_trace(renv, SIEVE_TRLVL_COMMANDS,
-		"%s %s:", sieve_operation_mnemonic(oprtn), str_c(mailbox));
+	if ( sieve_operation_is(oprtn, test_mailbox_create_operation) ) {
+		sieve_runtime_trace(renv, SIEVE_TRLVL_COMMANDS,
+			"test_mailbox :create `%s'", str_c(mailbox));
 
-	if ( sieve_operation_is(oprtn, test_mailbox_create_operation) )
 		testsuite_mailstore_mailbox_create(renv, str_c(mailbox));
+	}
 
 	return SIEVE_EXEC_OK;
 }
diff --git a/src/testsuite/cmd-test-message.c b/src/testsuite/cmd-test-message.c
index afb99848d..c4ea11c25 100644
--- a/src/testsuite/cmd-test-message.c
+++ b/src/testsuite/cmd-test-message.c
@@ -324,10 +324,10 @@ static int cmd_test_message_smtp_operation_execute
 		
 	if ( is_test )
 		sieve_runtime_trace(renv, SIEVE_TRLVL_TESTS,
-			"TEST_MESSAGE_SMTP test [%d]", msg_index);
+			"test_message test [smtp index=%d]", msg_index);
 	else
 		sieve_runtime_trace(renv, SIEVE_TRLVL_COMMANDS,
-			"TEST_MESSAGE_SMTP command [%d]", msg_index);
+			"text_message command [smtp index=%d]", msg_index);
 
 	result = testsuite_smtp_get(renv, msg_index);
 
@@ -374,10 +374,10 @@ static int cmd_test_message_mailbox_operation_execute
 
 	if ( is_test ) 		
 		sieve_runtime_trace(renv, SIEVE_TRLVL_TESTS, 
-			"TEST_MESSAGE_MAILBOX test \"%s\" [%d]", str_c(folder), msg_index);
+			"test_message test [mailbox=`%s' index=%d]", str_c(folder), msg_index);
 	else
 		sieve_runtime_trace(renv, SIEVE_TRLVL_COMMANDS, 
-			"TEST_MESSAGE_MAILBOX command \"%s\" [%d]", str_c(folder), msg_index);
+			"test_message command [mailbox=`%s' index=%d]", str_c(folder), msg_index);
 
 	result = testsuite_mailstore_mail_index(renv, str_c(folder), msg_index);
 
diff --git a/src/testsuite/cmd-test.c b/src/testsuite/cmd-test.c
index 00947e75f..dd6a78644 100644
--- a/src/testsuite/cmd-test.c
+++ b/src/testsuite/cmd-test.c
@@ -155,6 +155,7 @@ static int cmd_test_operation_execute
 	if ( !sieve_opr_string_read(renv, address, "test name", &test_name) )
 		return SIEVE_EXEC_BIN_CORRUPT;
 	
+	sieve_runtime_trace_sep(renv);
 	sieve_runtime_trace(renv, SIEVE_TRLVL_NONE, 
 		"** Test start: \"%s\"", str_c(test_name));
 
@@ -167,6 +168,7 @@ static int cmd_test_finish_operation_execute
 	sieve_size_t *address ATTR_UNUSED)
 {
 	sieve_runtime_trace(renv, SIEVE_TRLVL_NONE, "** Test end");
+	sieve_runtime_trace_sep(renv);
 	
 	testsuite_test_succeed(NULL);
 	return SIEVE_EXEC_OK;
diff --git a/src/testsuite/testsuite.c b/src/testsuite/testsuite.c
index a7020322f..51a60611d 100644
--- a/src/testsuite/testsuite.c
+++ b/src/testsuite/testsuite.c
@@ -48,7 +48,8 @@ const struct sieve_script_env *testsuite_scriptenv;
 static void print_help(void)
 {
 	printf(
-"Usage: testsuite [-t] [-E] [-d <dump filename>]\n"
+"Usage: testsuite [-E] [-d <dump-filename>]\n"
+"                 [-t <trace-filename>] [-T <trace-option>]\n"
 "                 [-P <plugin>] [-x <extensions>]\n"
 "                 <scriptfile>\n"
 	);
@@ -81,18 +82,21 @@ static int testsuite_run
 int main(int argc, char **argv) 
 {
 	struct sieve_instance *svinst;
-	const char *scriptfile, *dumpfile; 
+	const char *scriptfile, *dumpfile, *tracefile;
+	struct sieve_trace_config tr_config;
+	struct ostream *tracestream = NULL;
 	struct sieve_binary *sbin;
 	const char *sieve_dir;
-	bool trace = FALSE, log_stdout = FALSE;
+	bool log_stdout = FALSE;
 	int ret, c;
 
 	sieve_tool = sieve_tool_init
-		("testsuite", &argc, &argv, "d:tEP:", TRUE);
+		("testsuite", &argc, &argv, "d:t:T:EP:", TRUE);
 
 	/* Parse arguments */
-	scriptfile = dumpfile = NULL;
-
+	scriptfile = dumpfile = tracefile = NULL;
+	memset(&tr_config, 0, sizeof(tr_config));
+	tr_config.level = SIEVE_TRLVL_ACTIONS;
 	while ((c = sieve_tool_getopt(sieve_tool)) > 0) {
 		switch (c) {
 		case 'd':
@@ -100,7 +104,11 @@ int main(int argc, char **argv)
 			dumpfile = optarg;
 			break;
 		case 't':
-			trace = TRUE;
+			/* trace file */
+			tracefile = optarg;
+			break;
+		case 'T':
+			sieve_tool_parse_trace_option(&tr_config, optarg);
 			break;
 		case 'E':
 			log_stdout = TRUE;
@@ -166,6 +174,9 @@ int main(int argc, char **argv)
 		testsuite_mailstore_init();
 		testsuite_message_init();
 
+		if ( tracefile != NULL )
+            tracestream = sieve_tool_open_output_stream(tracefile);
+
 		memset(&scriptenv, 0, sizeof(scriptenv));
 		scriptenv.user = sieve_tool_get_mail_user(sieve_tool);
 		scriptenv.default_mailbox = "INBOX";
@@ -174,8 +185,8 @@ int main(int argc, char **argv)
 		scriptenv.username = sieve_tool_get_username(sieve_tool);
 		scriptenv.smtp_open = testsuite_smtp_open;
 		scriptenv.smtp_close = testsuite_smtp_close;
-		scriptenv.trace_stream = ( trace ? o_stream_create_fd(1, 0, FALSE) : NULL );
-		scriptenv.trace_config.level = SIEVE_TRLVL_TESTS;
+		scriptenv.trace_stream = tracestream;
+		scriptenv.trace_config = tr_config;
 
 		testsuite_scriptenv = &scriptenv;
 
diff --git a/src/testsuite/tst-test-error.c b/src/testsuite/tst-test-error.c
index 2e064f6b1..52905b9da 100644
--- a/src/testsuite/tst-test-error.c
+++ b/src/testsuite/tst-test-error.c
@@ -253,8 +253,12 @@ static int tst_test_error_operation_execute
 	 * Perform operation
 	 */
 	
-	sieve_runtime_trace(renv, SIEVE_TRLVL_TESTS,
-		"TEST_ERROR test (index: %d)", index);
+	if ( index > 0 )
+		sieve_runtime_trace(renv, SIEVE_TRLVL_TESTS,
+			"test_error test [index=%d]", index);
+	else
+		sieve_runtime_trace(renv, SIEVE_TRLVL_TESTS,
+			"test_error test");
 
 	testsuite_log_get_error_init();
 
diff --git a/src/testsuite/tst-test-multiscript.c b/src/testsuite/tst-test-multiscript.c
index 5ab3a6fac..2e678d3f9 100644
--- a/src/testsuite/tst-test-multiscript.c
+++ b/src/testsuite/tst-test-multiscript.c
@@ -117,7 +117,7 @@ static int tst_test_multiscript_operation_execute
 	 * Read operands
 	 */
 
-  if ( (scripts_list=sieve_opr_stringlist_read(renv, address, "scripts")) 
+	if ( (scripts_list=sieve_opr_stringlist_read(renv, address, "scripts")) 
 		== NULL )
 		return SIEVE_EXEC_BIN_CORRUPT;
 
@@ -125,7 +125,7 @@ static int tst_test_multiscript_operation_execute
 	 * Perform operation
 	 */
 
-	sieve_runtime_trace(renv, SIEVE_TRLVL_TESTS, "TEST MULTISCRIPT");
+	sieve_runtime_trace(renv, SIEVE_TRLVL_TESTS, "test_multiscript test");
 
 	t_array_init(&scriptfiles, 16);
 
diff --git a/src/testsuite/tst-test-result-execute.c b/src/testsuite/tst-test-result-execute.c
index 285e789c7..21e4c7dfe 100644
--- a/src/testsuite/tst-test-result-execute.c
+++ b/src/testsuite/tst-test-result-execute.c
@@ -74,7 +74,7 @@ static int tst_test_result_execute_operation_execute
 	 * Perform operation
 	 */
 
-	sieve_runtime_trace(renv, SIEVE_TRLVL_TESTS, "TEST_RESULT_EXECUTE test");
+	sieve_runtime_trace(renv, SIEVE_TRLVL_TESTS, "test_result_execute");
 
 	result = testsuite_result_execute(renv);
 
-- 
GitLab