From ea639eafab2c11f35e9c4d2390d5ee1d861fe733 Mon Sep 17 00:00:00 2001 From: Stephan Bosch <stephan@rename-it.nl> Date: Sat, 4 Sep 2010 14:53:35 +0200 Subject: [PATCH] Fixed runtime error logging not to report user-caused errors to the master log. --- TODO | 1 - src/lib-sieve/cmd-redirect.c | 10 +- src/lib-sieve/ext-reject.c | 2 +- src/lib-sieve/sieve-actions.c | 33 ++++--- src/lib-sieve/sieve-commands.h | 4 - src/lib-sieve/sieve-error.c | 121 ++++++++++++++++++++--- src/lib-sieve/sieve-error.h | 41 +++++++- src/lib-sieve/sieve-interpreter.c | 33 +++---- src/lib-sieve/sieve-result.c | 27 ++++- src/lib-sieve/sieve-result.h | 6 ++ src/lib-sieve/sieve-script.c | 10 +- src/lib-sieve/sieve-validator.c | 13 --- src/plugins/lda-sieve/lda-sieve-plugin.c | 26 +++-- 13 files changed, 239 insertions(+), 88 deletions(-) diff --git a/TODO b/TODO index 4053e21da..84c09e7c9 100644 --- a/TODO +++ b/TODO @@ -1,7 +1,6 @@ Current activities: * Improve error handling and logging - - Avoid reporting user-caused errors to the master log. - Review logging and error handling; add more warning/info/debug messages where useful. diff --git a/src/lib-sieve/cmd-redirect.c b/src/lib-sieve/cmd-redirect.c index e9c97a6d0..f682d9818 100644 --- a/src/lib-sieve/cmd-redirect.c +++ b/src/lib-sieve/cmd-redirect.c @@ -361,7 +361,7 @@ static bool act_redirect_commit const struct sieve_message_data *msgdata = aenv->msgdata; const struct sieve_script_env *senv = aenv->scriptenv; const char *dupeid; - + /* Prevent mail loops if possible */ dupeid = msgdata->id == NULL ? NULL : t_strdup_printf("%s-%s", msgdata->id, ctx->to_address); @@ -373,16 +373,16 @@ static bool act_redirect_commit return TRUE; } } - + /* Try to forward the message */ if ( act_redirect_send(aenv, ctx) ) { - + /* Mark this message id as forwarded to the specified destination */ if (dupeid != NULL) { sieve_action_duplicate_mark(senv, dupeid, strlen(dupeid), ioloop_time + CMD_REDIRECT_DUPLICATE_KEEP); } - + sieve_result_log(aenv, "forwarded to <%s>", str_sanitize(ctx->to_address, 128)); @@ -394,7 +394,7 @@ static bool act_redirect_commit return TRUE; } - + return FALSE; } diff --git a/src/lib-sieve/ext-reject.c b/src/lib-sieve/ext-reject.c index 411dbe972..7be036733 100644 --- a/src/lib-sieve/ext-reject.c +++ b/src/lib-sieve/ext-reject.c @@ -485,7 +485,7 @@ static bool act_reject_send fprintf(f, "\r\n\r\n--%s--\r\n", boundary); if ( !sieve_smtp_close(senv, smtp_handle) ) { - sieve_result_error(aenv, + sieve_result_error(aenv, "failed to send rejection message to <%s> " "(refer to server log for more information)", str_sanitize(sender, 80)); diff --git a/src/lib-sieve/sieve-actions.c b/src/lib-sieve/sieve-actions.c index c36a2aa1d..3d34576c6 100644 --- a/src/lib-sieve/sieve-actions.c +++ b/src/lib-sieve/sieve-actions.c @@ -500,14 +500,14 @@ static bool act_store_execute * succeeded. */ aenv->exec_status->last_storage = mailbox_get_storage(trans->box); - + /* Start mail transaction */ trans->mail_trans = mailbox_transaction_begin (trans->box, MAILBOX_TRANSACTION_FLAG_EXTERNAL); /* Create mail object for stored message */ trans->dest_mail = mail_alloc(trans->mail_trans, 0, NULL); - + /* Store the message */ save_ctx = mailbox_save_alloc(trans->mail_trans); mailbox_save_set_dest_mail(save_ctx, trans->dest_mail); @@ -515,7 +515,7 @@ static bool act_store_execute /* Apply keywords and flags that side-effects may have added */ if ( trans->flags_altered ) { keywords = act_store_keywords_create(aenv, &trans->keywords, trans->box); - + mailbox_save_set_flags(save_ctx, trans->flags, keywords); } @@ -523,12 +523,12 @@ static bool act_store_execute sieve_act_store_get_storage_error(aenv, trans); result = FALSE; } - + /* Deallocate keywords */ if ( keywords != NULL ) { mailbox_keywords_unref(trans->box, &keywords); } - + return result; } @@ -555,7 +555,7 @@ static void act_store_log_status /* Store disabled? */ if ( trans->disabled ) { sieve_result_log(aenv, "store into mailbox %s skipped", mailbox_name); - + /* Store redundant? */ } else if ( trans->redundant ) { sieve_result_log(aenv, "left message in mailbox %s", mailbox_name); @@ -563,16 +563,23 @@ static void act_store_log_status /* Store failed? */ } else if ( !status ) { const char *errstr; - enum mail_error error; + enum mail_error error_code; - if ( trans->error != NULL ) + if ( trans->error != NULL ) { errstr = trans->error; - else + error_code = trans->error_code; + } else { errstr = mail_storage_get_last_error - (mailbox_get_storage(trans->box), &error); - - sieve_result_error(aenv, "failed to store into mailbox %s: %s", - mailbox_name, errstr); + (mailbox_get_storage(trans->box), &error_code); + } + + if ( error_code != MAIL_ERROR_NOTFOUND || error_code != MAIL_ERROR_PARAMS ) { + sieve_result_error(aenv, "failed to store into mailbox %s: %s", + mailbox_name, errstr); + } else { + sieve_result_user_error(aenv, "failed to store into mailbox %s: %s", + mailbox_name, errstr); + } /* Store aborted? */ } else if ( rolled_back ) { diff --git a/src/lib-sieve/sieve-commands.h b/src/lib-sieve/sieve-commands.h index 58a7cfb00..ea6f3949f 100644 --- a/src/lib-sieve/sieve-commands.h +++ b/src/lib-sieve/sieve-commands.h @@ -192,13 +192,9 @@ bool sieve_command_block_exits_unconditionally sieve_validator_error(validator, (context)->ast_node->source_line, __VA_ARGS__) #define sieve_command_validate_warning(validator, context, ...) \ sieve_validator_warning(validator, (context)->ast_node->source_line, __VA_ARGS__) -#define sieve_command_validate_critical(validator, context, ...) \ - sieve_validator_critical(validator, (context)->ast_node->source_line, __VA_ARGS__) #define sieve_command_generate_error(gentr, context, ...) \ sieve_generator_error(gentr, (context)->ast_node->source_line, __VA_ARGS__) -#define sieve_command_generate_critical(gentr, context, ...) \ - sieve_generator_critical(gentr, (context)->ast_node->source_line, __VA_ARGS__) /* Utility macros */ diff --git a/src/lib-sieve/sieve-error.c b/src/lib-sieve/sieve-error.c index f13f1c5c0..0054357a1 100644 --- a/src/lib-sieve/sieve-error.c +++ b/src/lib-sieve/sieve-error.c @@ -65,6 +65,38 @@ void sieve_errors_deinit(struct sieve_instance *svinst) * System errors */ +void sieve_sys_verror +(struct sieve_instance *svinst, const char *fmt, va_list args) +{ + T_BEGIN { + sieve_verror(svinst->system_ehandler, NULL, fmt, args); + } T_END; +} + +void sieve_sys_vwarning +(struct sieve_instance *svinst, const char *fmt, va_list args) +{ + T_BEGIN { + sieve_vwarning(svinst->system_ehandler, NULL, fmt, args); + } T_END; +} + +void sieve_sys_vinfo +(struct sieve_instance *svinst, const char *fmt, va_list args) +{ + T_BEGIN { + sieve_vinfo(svinst->system_ehandler, NULL, fmt, args); + } T_END; +} + +void sieve_sys_vdebug +(struct sieve_instance *svinst, const char *fmt, va_list args) +{ + T_BEGIN { + sieve_vdebug(svinst->system_ehandler, NULL, fmt, args); + } T_END; +} + void sieve_sys_error(struct sieve_instance *svinst, const char *fmt, ...) { va_list args; @@ -123,6 +155,73 @@ void sieve_system_ehandler_set sieve_error_handler_ref(ehandler); } +/* + * User errors + */ + +void sieve_user_verror +(struct sieve_error_handler *ehandler, const char *location, + const char *fmt, va_list args) +{ + if ( ehandler == NULL ) return; + + sieve_direct_verror(ehandler, location, fmt, args); +} + +void sieve_user_vwarning +(struct sieve_error_handler *ehandler, const char *location, + const char *fmt, va_list args) +{ + if ( ehandler == NULL ) return; + + sieve_direct_vwarning(ehandler, location, fmt, args); +} + +void sieve_user_vinfo +(struct sieve_error_handler *ehandler, const char *location, + const char *fmt, va_list args) +{ + if ( ehandler == NULL ) return; + + sieve_direct_vinfo(ehandler, location, fmt, args); +} + +void sieve_user_error +(struct sieve_error_handler *ehandler, const char *location, + const char *fmt, ...) +{ + va_list args; + va_start(args, fmt); + + T_BEGIN { sieve_user_verror(ehandler, location, fmt, args); } T_END; + + va_end(args); +} + +void sieve_user_warning +(struct sieve_error_handler *ehandler, const char *location, + const char *fmt, ...) +{ + va_list args; + va_start(args, fmt); + + T_BEGIN { sieve_user_vwarning(ehandler, location, fmt, args); } T_END; + + va_end(args); +} + +void sieve_user_info +(struct sieve_error_handler *ehandler, const char *location, + const char *fmt, ...) +{ + va_list args; + va_start(args, fmt); + + T_BEGIN { sieve_user_vinfo(ehandler, location, fmt, args); } T_END; + + va_end(args); +} + /* * Main error functions */ @@ -187,23 +286,21 @@ void sieve_vdebug } void sieve_vcritical - (struct sieve_error_handler *ehandler, const char *location, - const char *fmt, va_list args) +(struct sieve_instance *svinst, struct sieve_error_handler *ehandler, + const char *location, const char *fmt, va_list args) { char str[256]; struct tm *tm; - - tm = localtime(&ioloop_time); - + if ( location == NULL || *location == '\0' ) { - sieve_sys_error - (ehandler->svinst, "%s", t_strdup_vprintf(fmt, args)); + sieve_verror(svinst->system_ehandler, NULL, fmt, args); } else { - sieve_sys_error - (ehandler->svinst, "%s: %s", location, t_strdup_vprintf(fmt, args)); + sieve_verror(svinst->system_ehandler, location, fmt, args); } if ( ehandler == NULL ) return; + + tm = localtime(&ioloop_time); sieve_error(ehandler, location, "%s", strftime(str, sizeof(str), CRITICAL_MSG_STAMP, tm) > 0 ? @@ -259,13 +356,13 @@ void sieve_debug } void sieve_critical -(struct sieve_error_handler *ehandler, const char *location, - const char *fmt, ...) +(struct sieve_instance *svinst, struct sieve_error_handler *ehandler, + const char *location, const char *fmt, ...) { va_list args; va_start(args, fmt); - T_BEGIN { sieve_vcritical(ehandler, location, fmt, args); } T_END; + T_BEGIN { sieve_vcritical(svinst, ehandler, location, fmt, args); } T_END; va_end(args); } diff --git a/src/lib-sieve/sieve-error.h b/src/lib-sieve/sieve-error.h index 5fb8c8f44..752d2c71e 100644 --- a/src/lib-sieve/sieve-error.h +++ b/src/lib-sieve/sieve-error.h @@ -34,6 +34,15 @@ typedef void (*sieve_error_func_t) * System errors */ +void sieve_sys_verror + (struct sieve_instance *svinst, const char *fmt, va_list args); +void sieve_sys_vwarning + (struct sieve_instance *svinst, const char *fmt, va_list args); +void sieve_sys_vinfo + (struct sieve_instance *svinst, const char *fmt, va_list args); +void sieve_sys_vdebug + (struct sieve_instance *svinst, const char *fmt, va_list args); + void sieve_sys_error (struct sieve_instance *svinst, const char *fmt, ...) ATTR_FORMAT(2, 3); void sieve_sys_warning @@ -46,6 +55,30 @@ void sieve_sys_debug void sieve_system_ehandler_set (struct sieve_error_handler *ehandler); +/* + * User errors + */ + +void sieve_user_verror + (struct sieve_error_handler *ehandler, const char *location, + const char *fmt, va_list args); +void sieve_user_vwarning + (struct sieve_error_handler *ehandler, const char *location, + const char *fmt, va_list args); +void sieve_user_vinfo + (struct sieve_error_handler *ehandler, const char *location, + const char *fmt, va_list args); + +void sieve_user_error +(struct sieve_error_handler *ehandler, const char *location, + const char *fmt, ...) ATTR_FORMAT(3, 4); +void sieve_user_warning +(struct sieve_error_handler *ehandler, const char *location, + const char *fmt, ...) ATTR_FORMAT(3, 4); +void sieve_user_info +(struct sieve_error_handler *ehandler, const char *location, + const char *fmt, ...) ATTR_FORMAT(3, 4); + /* * Main error functions */ @@ -70,8 +103,8 @@ void sieve_vdebug (struct sieve_error_handler *ehandler, const char *location, const char *fmt, va_list args); void sieve_vcritical - (struct sieve_error_handler *ehandler, const char *location, - const char *fmt, va_list args); + (struct sieve_instance *svinst, struct sieve_error_handler *ehandler, + const char *location, const char *fmt, va_list args); void sieve_error (struct sieve_error_handler *ehandler, const char *location, @@ -86,8 +119,8 @@ void sieve_debug (struct sieve_error_handler *ehandler, const char *location, const char *fmt, ...) ATTR_FORMAT(3, 4); void sieve_critical -(struct sieve_error_handler *ehandler, const char *location, - const char *fmt, ...) ATTR_FORMAT(3, 4); +(struct sieve_instance *svinst, struct sieve_error_handler *ehandler, + const char *location, const char *fmt, ...) ATTR_FORMAT(4, 5); /* * Error handler configuration diff --git a/src/lib-sieve/sieve-interpreter.c b/src/lib-sieve/sieve-interpreter.c index c9001e853..61f8dce90 100644 --- a/src/lib-sieve/sieve-interpreter.c +++ b/src/lib-sieve/sieve-interpreter.c @@ -271,19 +271,26 @@ void sieve_interpreter_set_result * Error handling */ +static inline void sieve_runtime_vmsg +(const struct sieve_runtime_env *renv, sieve_error_vfunc_t msg_func, + const char *location, const char *fmt, va_list args) +{ + T_BEGIN { + if ( location == NULL ) + location = sieve_runtime_get_full_command_location(renv); + + msg_func(renv->interp->ehandler, location, fmt, args); + } T_END; +} + void sieve_runtime_error (const struct sieve_runtime_env *renv, const char *location, const char *fmt, ...) { va_list args; - if ( location == NULL ) - location = sieve_runtime_get_full_command_location(renv); - va_start(args, fmt); - T_BEGIN { - sieve_verror(renv->interp->ehandler, location, fmt, args); - } T_END; + sieve_runtime_vmsg(renv, sieve_user_verror, location, fmt, args); va_end(args); } @@ -293,13 +300,8 @@ void sieve_runtime_warning { va_list args; - if ( location == NULL ) - location = sieve_runtime_get_full_command_location(renv); - va_start(args, fmt); - T_BEGIN { - sieve_vwarning(renv->interp->ehandler, location, fmt, args); - } T_END; + sieve_runtime_vmsg(renv, sieve_user_vwarning, location, fmt, args); va_end(args); } @@ -309,13 +311,8 @@ void sieve_runtime_log { va_list args; - if ( location == NULL ) - location = sieve_runtime_get_full_command_location(renv); - va_start(args, fmt); - T_BEGIN { - sieve_vinfo(renv->interp->ehandler, location, fmt, args); - } T_END; + sieve_runtime_vmsg(renv, sieve_user_vinfo, location, fmt, args); va_end(args); } diff --git a/src/lib-sieve/sieve-result.c b/src/lib-sieve/sieve-result.c index 45e955300..2e332d7c6 100644 --- a/src/lib-sieve/sieve-result.c +++ b/src/lib-sieve/sieve-result.c @@ -240,6 +240,16 @@ void sieve_result_error va_end(args); } +void sieve_result_user_error +(const struct sieve_action_exec_env *aenv, const char *fmt, ...) +{ + va_list args; + + va_start(args, fmt); + sieve_user_verror(aenv->ehandler, NULL, fmt, args); + va_end(args); +} + void sieve_result_warning (const struct sieve_action_exec_env *aenv, const char *fmt, ...) { @@ -250,6 +260,17 @@ void sieve_result_warning va_end(args); } +void sieve_result_user_warning +(const struct sieve_action_exec_env *aenv, const char *fmt, ...) +{ + va_list args; + + va_start(args, fmt); + sieve_user_vwarning(aenv->ehandler, NULL, fmt, args); + va_end(args); +} + + void sieve_result_log (const struct sieve_action_exec_env *aenv, const char *fmt, ...) { @@ -533,8 +554,8 @@ static int _sieve_result_add_action sieve_runtime_error(renv, action.location, "number of %s actions exceeds policy limit", act_def->name); return -1; - } - + } + if ( kaction != NULL ) { /* Use existing keep action to define new one */ raction = kaction; @@ -546,7 +567,7 @@ static int _sieve_result_add_action raction->tr_context = NULL; raction->success = FALSE; } - + raction->action.context = context; raction->action.def = act_def; raction->action.ext = ext; diff --git a/src/lib-sieve/sieve-result.h b/src/lib-sieve/sieve-result.h index f5991379d..2ce25767e 100644 --- a/src/lib-sieve/sieve-result.h +++ b/src/lib-sieve/sieve-result.h @@ -87,9 +87,15 @@ bool sieve_result_print */ void sieve_result_error +(const struct sieve_action_exec_env *aenv, const char *fmt, ...) + ATTR_FORMAT(2, 3); +void sieve_result_user_error (const struct sieve_action_exec_env *aenv, const char *fmt, ...) ATTR_FORMAT(2, 3); void sieve_result_warning +(const struct sieve_action_exec_env *aenv, const char *fmt, ...) + ATTR_FORMAT(2, 3); +void sieve_result_user_warning (const struct sieve_action_exec_env *aenv, const char *fmt, ...) ATTR_FORMAT(2, 3); void sieve_result_log diff --git a/src/lib-sieve/sieve-script.c b/src/lib-sieve/sieve-script.c index 9f8765a53..4ecc78611 100644 --- a/src/lib-sieve/sieve-script.c +++ b/src/lib-sieve/sieve-script.c @@ -147,14 +147,14 @@ static void sieve_script_handle_file_error } break; case EACCES: - sieve_critical(ehandler, name, + sieve_critical(svinst, ehandler, name, "failed to stat sieve script: %s", eacces_error_get("stat", path)); if ( error_r != NULL ) *error_r = SIEVE_ERROR_NO_PERM; break; default: - sieve_critical(ehandler, name, + sieve_critical(svinst, ehandler, name, "failed to stat sieve script: stat(%s) failed: %m", path); if ( error_r != NULL ) *error_r = SIEVE_ERROR_TEMP_FAIL; @@ -228,7 +228,7 @@ struct sieve_script *sieve_script_init } if ( ret == 0 && !S_ISREG(st.st_mode) ) { - sieve_critical(ehandler, basename, + sieve_critical(svinst, ehandler, basename, "sieve script file '%s' is not a regular file.", path); if ( error_r != NULL ) *error_r = SIEVE_ERROR_NOT_POSSIBLE; @@ -380,7 +380,7 @@ struct istream *sieve_script_open } if ( fstat(fd, &st) != 0 ) { - sieve_critical(script->ehandler, script->path, + sieve_critical(script->svinst, script->ehandler, script->path, "failed to open sieve script: fstat(fd=%s) failed: %m", script->path); if ( error_r != NULL ) *error_r = SIEVE_ERROR_TEMP_FAIL; @@ -388,7 +388,7 @@ struct istream *sieve_script_open } else { /* Re-check the file type just to be sure */ if ( !S_ISREG(st.st_mode) ) { - sieve_critical(script->ehandler, script->path, + sieve_critical(script->svinst, script->ehandler, script->path, "sieve script file '%s' is not a regular file", script->path); if ( error_r != NULL ) *error_r = SIEVE_ERROR_NOT_POSSIBLE; diff --git a/src/lib-sieve/sieve-validator.c b/src/lib-sieve/sieve-validator.c index ba9842b94..cb3f109e6 100644 --- a/src/lib-sieve/sieve-validator.c +++ b/src/lib-sieve/sieve-validator.c @@ -136,19 +136,6 @@ void sieve_validator_error va_end(args); } -void sieve_validator_critical -(struct sieve_validator *valdtr, unsigned int source_line, - const char *fmt, ...) -{ - va_list args; - - va_start(args, fmt); - sieve_vcritical(valdtr->ehandler, - sieve_error_script_location(valdtr->script, source_line), - fmt, args); - va_end(args); -} - /* * Validator object */ diff --git a/src/plugins/lda-sieve/lda-sieve-plugin.c b/src/plugins/lda-sieve/lda-sieve-plugin.c index 3fa7a9d8d..4749f3498 100644 --- a/src/plugins/lda-sieve/lda-sieve-plugin.c +++ b/src/plugins/lda-sieve/lda-sieve-plugin.c @@ -281,7 +281,7 @@ static struct sieve_binary *lda_sieve_open if ( script_path == srctx->user_script && srctx->userlog != NULL ) { sieve_sys_error(svinst, "failed to open script %s " - "(view logfile %s for more information)", + "(view user logfile %s for more information)", script_path, srctx->userlog); } else { sieve_sys_error(svinst, @@ -325,7 +325,7 @@ static struct sieve_binary *lda_sieve_recompile if ( script_path == srctx->user_script && srctx->userlog != NULL ) { sieve_sys_error(svinst, "failed to re-compile script %s " - "(view logfile %s for more information)", + "(view user logfile %s for more information)", script_path, srctx->userlog); } else { sieve_sys_error(svinst, @@ -342,25 +342,32 @@ static int lda_sieve_handle_exec_status (struct lda_sieve_run_context *srctx, const char *script_path, int status) { struct sieve_instance *svinst = srctx->svinst; + const char *userlog_notice = ""; int ret; + if ( script_path == srctx->user_script && srctx->userlog != NULL ) { + userlog_notice = t_strdup_printf + (" (user logfile %s may reveal additional details)", srctx->userlog); + } + switch ( status ) { case SIEVE_EXEC_FAILURE: sieve_sys_error(svinst, - "execution of script %s failed, but implicit keep was successful", - script_path); + "execution of script %s failed, but implicit keep was successful%s", + script_path, userlog_notice); ret = 1; break; case SIEVE_EXEC_BIN_CORRUPT: sieve_sys_error(svinst, "!!BUG!!: binary compiled from %s is still corrupt; " - "bailing out and reverting to default delivery", - script_path); + "bailing out and reverting to default delivery", + script_path); ret = -1; break; case SIEVE_EXEC_KEEP_FAILED: sieve_sys_error(svinst, - "script %s failed with unsuccessful implicit keep", script_path); + "script %s failed with unsuccessful implicit keep%s", + script_path, userlog_notice); ret = -1; break; default: @@ -419,10 +426,11 @@ static int lda_sieve_singlescript_execute /* Execute again */ if ( debug ) - sieve_sys_debug(svinst, "executing script from %s", sieve_get_source(sbin)); + sieve_sys_debug + (svinst, "executing script from %s", sieve_get_source(sbin)); if ( user_script ) - sieve_error_handler_copy_masterlog(ehandler, TRUE); + sieve_error_handler_copy_masterlog(ehandler, TRUE); ret = sieve_execute(sbin, srctx->msgdata, srctx->scriptenv, ehandler, NULL); -- GitLab