diff --git a/TODO b/TODO index 4053e21da524c069f58165fa3f5d4ea678e61f7d..84c09e7c9bf84b933da8112cc043b52027d7d1a0 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 e9c97a6d04144bba9539afb9a98fdeeadb52be5b..f682d9818b3e8941624d5bad11638303400c3e1f 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 411dbe972c7e60c5eea9ff9406a056628461f760..7be0367332db88029e5fed80800c00b86a183fbb 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 c36a2aa1d0ab553c4246b406e915d8998a3b5176..3d34576c68052f37ad6b30244d707abf7a425879 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 58a7cfb00eeed43d6ce19458040a857432bb3597..ea6f3949f9c0bed70a98bd185fffd54bac98fcda 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 f13f1c5c0b912dbb95bded6a7fc2765913bf3b57..0054357a1731c41570eb1ed3e3d65dea262cdc62 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 5fb8c8f44cc86209dbc52e481e1e956553c630f9..752d2c71eaf7f7abcd5e4f97b37411844d1ff7a5 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 c9001e853ffa9f5fe12fe490aa7dbd62736066ca..61f8dce90f0aa1f71a5f68f00e79a202941c00d9 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 45e955300423555ac61d3a95cd5f324b59a64da2..2e332d7c6cd5eba706e757cf26e7761d3bb04d04 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 f5991379dbbb2a602a943f4c55978ce56ebeaa3b..2ce25767ed241d61130d8e9f99041f95b4f7fe69 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 9f8765a53f5aebf131d451a1faf54d8aed1d81bc..4ecc78611cc4e40e3c36cad3713fcf1ecf75d1e6 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 ba9842b947c6f881e0bbf67b6cca6e2965ee85e1..cb3f109e63a32cc9ea60da1f534d38912239ca45 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 3fa7a9d8dc7bae2609051e020bdd3724ba45de38..4749f3498657f57b6fe84424a0e0ad4ba3a4791c 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);