diff options
Diffstat (limited to 'src')
-rw-r--r-- | src/src/acl.c | 152 | ||||
-rw-r--r-- | src/src/debug.c | 24 | ||||
-rw-r--r-- | src/src/expand.c | 85 | ||||
-rw-r--r-- | src/src/functions.h | 2 | ||||
-rw-r--r-- | src/src/globals.c | 3 | ||||
-rw-r--r-- | src/src/globals.h | 2 | ||||
-rw-r--r-- | src/src/malware.c | 44 | ||||
-rw-r--r-- | src/src/mime.c | 24 | ||||
-rw-r--r-- | src/src/pdkim/rsa.c | 34 | ||||
-rw-r--r-- | src/src/receive.c | 20 | ||||
-rw-r--r-- | src/src/smtp_out.c | 28 | ||||
-rw-r--r-- | src/src/spam.c | 10 | ||||
-rw-r--r-- | src/src/transports/smtp.c | 4 | ||||
-rw-r--r-- | src/src/transports/smtp_socks.c | 26 | ||||
-rw-r--r-- | src/src/verify.c | 30 |
15 files changed, 264 insertions, 224 deletions
diff --git a/src/src/acl.c b/src/src/acl.c index 396e29965..60fa97752 100644 --- a/src/src/acl.c +++ b/src/src/acl.c @@ -573,7 +573,7 @@ static uschar *ratelimit_option_string[] = { /* Enable recursion between acl_check_internal() and acl_check_condition() */ -static int acl_check_wargs(int, address_item *, const uschar *, int, uschar **, +static int acl_check_wargs(int, address_item *, const uschar *, uschar **, uschar **); @@ -1167,7 +1167,7 @@ if (host_lookup_failed) /* Need to do a lookup */ HDEBUG(D_acl) - debug_printf("looking up host name to force name/address consistency check\n"); + debug_printf_indent("looking up host name to force name/address consistency check\n"); if ((rc = host_name_lookup()) != OK) { @@ -1241,7 +1241,7 @@ for (rr = dns_next_rr(dnsa, dnss, reset); { /* If the client IP address matches the target IP address, it's good! */ - DEBUG(D_acl) debug_printf("CSA target address is %s\n", da->address); + DEBUG(D_acl) debug_printf_indent("CSA target address is %s\n", da->address); if (strcmpic(sender_host_address, da->address) == 0) return CSA_OK; } @@ -1372,7 +1372,7 @@ for (rr = dns_next_rr(&dnsa, &dnss, RESET_ANSWERS); GETSHORT(port, p); DEBUG(D_acl) - debug_printf("CSA priority=%d weight=%d port=%d\n", priority, weight, port); + debug_printf_indent("CSA priority=%d weight=%d port=%d\n", priority, weight, port); /* Check the CSA version number */ @@ -1404,7 +1404,7 @@ for (rr = dns_next_rr(&dnsa, &dnss, RESET_ANSWERS); (void)dn_expand(dnsa.answer, dnsa.answer + dnsa.answerlen, p, (DN_EXPAND_ARG4_TYPE)target, sizeof(target)); - DEBUG(D_acl) debug_printf("CSA target is %s\n", target); + DEBUG(D_acl) debug_printf_indent("CSA target is %s\n", target); break; } @@ -1633,7 +1633,7 @@ switch(vp->value) *log_msgptr = *user_msgptr = string_sprintf("client SMTP authorization %s", csa_reason_string[rc]); csa_status = csa_status_string[rc]; - DEBUG(D_acl) debug_printf("CSA result %s\n", csa_status); + DEBUG(D_acl) debug_printf_indent("CSA result %s\n", csa_status); return csa_return_code[rc]; case VERIFY_HDR_SYNTAX: @@ -1888,7 +1888,7 @@ else if (verify_sender_address) rc = sender_vaddr->special_action; *basic_errno = sender_vaddr->basic_errno; } - HDEBUG(D_acl) debug_printf("using cached sender verify result\n"); + HDEBUG(D_acl) debug_printf_indent("using cached sender verify result\n"); } /* Do a new verification, and cache the result. The cache is used to avoid @@ -1935,7 +1935,7 @@ else if (verify_sender_address) rc = verify_address(sender_vaddr, NULL, verify_options, callout, callout_overall, callout_connect, se_mailfrom, pm_mailfrom, &routed); - HDEBUG(D_acl) debug_printf("----------- end verify ------------\n"); + HDEBUG(D_acl) debug_printf_indent("----------- end verify ------------\n"); if (rc != OK) *basic_errno = sender_vaddr->basic_errno; @@ -1943,10 +1943,10 @@ else if (verify_sender_address) DEBUG(D_acl) { if (Ustrcmp(sender_vaddr->address, verify_sender_address) != 0) - debug_printf("sender %s verified ok as %s\n", + debug_printf_indent("sender %s verified ok as %s\n", verify_sender_address, sender_vaddr->address); else - debug_printf("sender %s verified ok\n", + debug_printf_indent("sender %s verified ok\n", verify_sender_address); } } @@ -1988,7 +1988,7 @@ else addr2 = *addr; rc = verify_address(&addr2, NULL, verify_options|vopt_is_recipient, callout, callout_overall, callout_connect, se_mailfrom, pm_mailfrom, NULL); - HDEBUG(D_acl) debug_printf("----------- end verify ------------\n"); + HDEBUG(D_acl) debug_printf_indent("----------- end verify ------------\n"); *basic_errno = addr2.basic_errno; *log_msgptr = addr2.message; @@ -2007,7 +2007,7 @@ else if (rc == DEFER && (defer_ok || (callout_defer_ok && *basic_errno == ERRNO_CALLOUTDEFER))) { - HDEBUG(D_acl) debug_printf("verify defer overridden by %s\n", + HDEBUG(D_acl) debug_printf_indent("verify defer overridden by %s\n", defer_ok? "defer_ok" : "callout_defer_ok"); rc = OK; } @@ -2306,7 +2306,7 @@ key = string_sprintf("%s/%s/%s%s", key); HDEBUG(D_acl) - debug_printf("ratelimit condition count=%.0f %.1f/%s\n", count, limit, key); + debug_printf_indent("ratelimit condition count=%.0f %.1f/%s\n", count, limit, key); /* See if we have already computed the rate by looking in the relevant tree. For per-connection rate limiting, store tree nodes and dbdata in the permanent @@ -2349,7 +2349,7 @@ if (t != NULL) store_pool = old_pool; sender_rate = string_sprintf("%.1f", dbd->rate); HDEBUG(D_acl) - debug_printf("ratelimit found pre-computed rate %s\n", sender_rate); + debug_printf_indent("ratelimit found pre-computed rate %s\n", sender_rate); return rc; } @@ -2361,7 +2361,7 @@ if (dbm == NULL) { store_pool = old_pool; sender_rate = NULL; - HDEBUG(D_acl) debug_printf("ratelimit database not available\n"); + HDEBUG(D_acl) debug_printf_indent("ratelimit database not available\n"); *log_msgptr = US"ratelimit database not available"; return DEFER; } @@ -2373,7 +2373,7 @@ gettimeofday(&tv, NULL); if (dbdb != NULL) { /* Locate the basic ratelimit block inside the DB data. */ - HDEBUG(D_acl) debug_printf("ratelimit found key in database\n"); + HDEBUG(D_acl) debug_printf_indent("ratelimit found key in database\n"); dbd = &dbdb->dbd; /* Forget the old Bloom filter if it is too old, so that we count each @@ -2383,7 +2383,7 @@ if (dbdb != NULL) if(unique != NULL && tv.tv_sec > dbdb->bloom_epoch + period) { - HDEBUG(D_acl) debug_printf("ratelimit discarding old Bloom filter\n"); + HDEBUG(D_acl) debug_printf_indent("ratelimit discarding old Bloom filter\n"); dbdb = NULL; } @@ -2391,7 +2391,7 @@ if (dbdb != NULL) if(unique != NULL && dbdb_size < sizeof(*dbdb)) { - HDEBUG(D_acl) debug_printf("ratelimit discarding undersize Bloom filter\n"); + HDEBUG(D_acl) debug_printf_indent("ratelimit discarding undersize Bloom filter\n"); dbdb = NULL; } } @@ -2404,14 +2404,14 @@ if (dbdb == NULL) if (unique == NULL) { /* No Bloom filter. This basic ratelimit block is initialized below. */ - HDEBUG(D_acl) debug_printf("ratelimit creating new rate data block\n"); + HDEBUG(D_acl) debug_printf_indent("ratelimit creating new rate data block\n"); dbdb_size = sizeof(*dbd); dbdb = store_get(dbdb_size); } else { int extra; - HDEBUG(D_acl) debug_printf("ratelimit creating new Bloom filter\n"); + HDEBUG(D_acl) debug_printf_indent("ratelimit creating new Bloom filter\n"); /* See the long comment below for an explanation of the magic number 2. The filter has a minimum size in case the rate limit is very small; @@ -2495,7 +2495,7 @@ if (unique != NULL && !readonly) /* Scan the bits corresponding to this event. A zero bit means we have not seen it before. Ensure all bits are set to record this event. */ - HDEBUG(D_acl) debug_printf("ratelimit checking uniqueness of %s\n", unique); + HDEBUG(D_acl) debug_printf_indent("ratelimit checking uniqueness of %s\n", unique); seen = TRUE; for (n = 0; n < 8; n++, hash += hinc) @@ -2513,11 +2513,11 @@ if (unique != NULL && !readonly) if (seen) { - HDEBUG(D_acl) debug_printf("ratelimit event found in Bloom filter\n"); + HDEBUG(D_acl) debug_printf_indent("ratelimit event found in Bloom filter\n"); count = 0.0; } else - HDEBUG(D_acl) debug_printf("ratelimit event added to Bloom filter\n"); + HDEBUG(D_acl) debug_printf_indent("ratelimit event added to Bloom filter\n"); } /* If there was no previous ratelimit data block for this key, initialize @@ -2526,7 +2526,7 @@ is what would be computed by the code below for an infinite interval. */ if (dbd == NULL) { - HDEBUG(D_acl) debug_printf("ratelimit initializing new key's rate data\n"); + HDEBUG(D_acl) debug_printf_indent("ratelimit initializing new key's rate data\n"); dbd = &dbdb->dbd; dbd->time_stamp = tv.tv_sec; dbd->time_usec = tv.tv_usec; @@ -2627,11 +2627,11 @@ neither leaky nor strict are set, so we do not do any updates. */ if ((rc == FAIL && leaky) || strict) { dbfn_write(dbm, key, dbdb, dbdb_size); - HDEBUG(D_acl) debug_printf("ratelimit db updated\n"); + HDEBUG(D_acl) debug_printf_indent("ratelimit db updated\n"); } else { - HDEBUG(D_acl) debug_printf("ratelimit db not updated: %s\n", + HDEBUG(D_acl) debug_printf_indent("ratelimit db not updated: %s\n", readonly? "readonly mode" : "over the limit, but leaky"); } @@ -2651,7 +2651,7 @@ store_pool = old_pool; sender_rate = string_sprintf("%.1f", dbd->rate); HDEBUG(D_acl) - debug_printf("ratelimit computed rate %s\n", sender_rate); + debug_printf_indent("ratelimit computed rate %s\n", sender_rate); return rc; } @@ -2729,7 +2729,7 @@ if (r == HOST_FIND_FAILED || r == HOST_FIND_AGAIN) } HDEBUG(D_acl) - debug_printf("udpsend [%s]:%d %s\n", h->address, portnum, arg); + debug_printf_indent("udpsend [%s]:%d %s\n", h->address, portnum, arg); r = s = ip_connectedsocket(SOCK_DGRAM, h->address, portnum, portnum, 1, NULL, &errstr); @@ -2751,7 +2751,7 @@ if (r < len) } HDEBUG(D_acl) - debug_printf("udpsend %d bytes\n", r); + debug_printf_indent("udpsend %d bytes\n", r); return OK; @@ -2813,14 +2813,14 @@ for (; cb != NULL; cb = cb->next) if (cb->type == ACLC_MESSAGE) { - HDEBUG(D_acl) debug_printf(" message: %s\n", cb->arg); + HDEBUG(D_acl) debug_printf_indent(" message: %s\n", cb->arg); user_message = cb->arg; continue; } if (cb->type == ACLC_LOG_MESSAGE) { - HDEBUG(D_acl) debug_printf("l_message: %s\n", cb->arg); + HDEBUG(D_acl) debug_printf_indent("l_message: %s\n", cb->arg); log_message = cb->arg; continue; } @@ -2853,7 +2853,7 @@ for (; cb != NULL; cb = cb->next) HDEBUG(D_acl) { int lhswidth = 0; - debug_printf("check %s%s %n", + debug_printf_indent("check %s%s %n", (!conditions[cb->type].is_modifier && cb->u.negated)? "!":"", conditions[cb->type].name, &lhswidth); @@ -2893,7 +2893,7 @@ for (; cb != NULL; cb = cb->next) "discard" verb. */ case ACLC_ACL: - rc = acl_check_wargs(where, addr, arg, level+1, user_msgptr, log_msgptr); + rc = acl_check_wargs(where, addr, arg, user_msgptr, log_msgptr); if (rc == DISCARD && verb != ACL_ACCEPT && verb != ACL_DISCARD) { *log_msgptr = string_sprintf("nested ACL returned \"discard\" for " @@ -2998,7 +2998,7 @@ for (; cb != NULL; cb = cb->next) if (af < 0) { HDEBUG(D_acl) - debug_printf("smtp input is probably not a socket [%s], not setting DSCP\n", + debug_printf_indent("smtp input is probably not a socket [%s], not setting DSCP\n", strerror(errno)); break; } @@ -3006,12 +3006,12 @@ for (; cb != NULL; cb = cb->next) { if (setsockopt(fd, level, optname, &value, sizeof(value)) < 0) { - HDEBUG(D_acl) debug_printf("failed to set input DSCP[%s]: %s\n", + HDEBUG(D_acl) debug_printf_indent("failed to set input DSCP[%s]: %s\n", p+1, strerror(errno)); } else { - HDEBUG(D_acl) debug_printf("set input DSCP to \"%s\"\n", p+1); + HDEBUG(D_acl) debug_printf_indent("set input DSCP to \"%s\"\n", p+1); } } else @@ -3306,12 +3306,12 @@ for (; cb != NULL; cb = cb->next) } else { - HDEBUG(D_acl) debug_printf("delay modifier requests %d-second delay\n", + HDEBUG(D_acl) debug_printf_indent("delay modifier requests %d-second delay\n", delay); if (host_checking) { HDEBUG(D_acl) - debug_printf("delay skipped in -bh checking mode\n"); + debug_printf_indent("delay skipped in -bh checking mode\n"); } /* NOTE 1: Remember that we may be @@ -3339,7 +3339,7 @@ for (; cb != NULL; cb = cb->next) n = 1; } if (poll(&p, n, delay*1000) > 0) - HDEBUG(D_acl) debug_printf("delay cancelled by peer close\n"); + HDEBUG(D_acl) debug_printf_indent("delay cancelled by peer close\n"); } #else /* It appears to be impossible to detect that a TCP/IP connection has @@ -3842,7 +3842,6 @@ Arguments: where where called from addr address item when called from RCPT; otherwise NULL s the input string; NULL is the same as an empty ACL => DENY - level the nesting level user_msgptr where to put a user error (for SMTP response) log_msgptr where to put a logging message (not for SMTP response) @@ -3855,7 +3854,7 @@ Returns: OK access is granted */ static int -acl_check_internal(int where, address_item *addr, uschar *s, int level, +acl_check_internal(int where, address_item *addr, uschar *s, uschar **user_msgptr, uschar **log_msgptr) { int fd = -1; @@ -3865,25 +3864,24 @@ uschar *ss; /* Catch configuration loops */ -if (level > 20) +if (acl_level > 20) { *log_msgptr = US"ACL nested too deep: possible loop"; return ERROR; } -if (s == NULL) +if (!s) { - HDEBUG(D_acl) debug_printf("ACL is NULL: implicit DENY\n"); + HDEBUG(D_acl) debug_printf_indent("ACL is NULL: implicit DENY\n"); return FAIL; } /* At top level, we expand the incoming string. At lower levels, it has already been expanded as part of condition processing. */ -if (level == 0) +if (acl_level == 0) { - ss = expand_string(s); - if (ss == NULL) + if (!(ss = expand_string(s))) { if (expand_string_forcedfail) return OK; *log_msgptr = string_sprintf("failed to expand ACL string \"%s\": %s", s, @@ -3914,11 +3912,11 @@ if (Ustrchr(ss, ' ') == NULL) acl = (acl_block *)(t->data.ptr); if (acl == NULL) { - HDEBUG(D_acl) debug_printf("ACL \"%s\" is empty: implicit DENY\n", ss); + HDEBUG(D_acl) debug_printf_indent("ACL \"%s\" is empty: implicit DENY\n", ss); return FAIL; } acl_name = string_sprintf("ACL \"%s\"", ss); - HDEBUG(D_acl) debug_printf("using ACL \"%s\"\n", ss); + HDEBUG(D_acl) debug_printf_indent("using ACL \"%s\"\n", ss); } else if (*ss == '/') @@ -3952,7 +3950,7 @@ if (Ustrchr(ss, ' ') == NULL) (void)close(fd); acl_name = string_sprintf("ACL \"%s\"", ss); - HDEBUG(D_acl) debug_printf("read ACL from file %s\n", ss); + HDEBUG(D_acl) debug_printf_indent("read ACL from file %s\n", ss); } } @@ -3983,19 +3981,19 @@ while (acl != NULL) int cond; int basic_errno = 0; BOOL endpass_seen = FALSE; - BOOL acl_quit_check = level == 0 + BOOL acl_quit_check = acl_level == 0 && (where == ACL_WHERE_QUIT || where == ACL_WHERE_NOTQUIT); *log_msgptr = *user_msgptr = NULL; acl_temp_details = FALSE; - HDEBUG(D_acl) debug_printf("processing \"%s\"\n", verbs[acl->verb]); + HDEBUG(D_acl) debug_printf_indent("processing \"%s\"\n", verbs[acl->verb]); /* Clear out any search error message from a previous check before testing this condition. */ search_error_message = NULL; - cond = acl_check_condition(acl->verb, acl->condition, where, addr, level, + cond = acl_check_condition(acl->verb, acl->condition, where, addr, acl_level, &endpass_seen, user_msgptr, log_msgptr, &basic_errno); /* Handle special returns: DEFER causes a return except on a WARN verb; @@ -4004,7 +4002,7 @@ while (acl != NULL) switch (cond) { case DEFER: - HDEBUG(D_acl) debug_printf("%s: condition test deferred in %s\n", verbs[acl->verb], acl_name); + HDEBUG(D_acl) debug_printf_indent("%s: condition test deferred in %s\n", verbs[acl->verb], acl_name); if (basic_errno != ERRNO_CALLOUTDEFER) { if (search_error_message != NULL && *search_error_message != 0) @@ -4020,28 +4018,28 @@ while (acl != NULL) default: /* Paranoia */ case ERROR: - HDEBUG(D_acl) debug_printf("%s: condition test error in %s\n", verbs[acl->verb], acl_name); + HDEBUG(D_acl) debug_printf_indent("%s: condition test error in %s\n", verbs[acl->verb], acl_name); return ERROR; case OK: - HDEBUG(D_acl) debug_printf("%s: condition test succeeded in %s\n", + HDEBUG(D_acl) debug_printf_indent("%s: condition test succeeded in %s\n", verbs[acl->verb], acl_name); break; case FAIL: - HDEBUG(D_acl) debug_printf("%s: condition test failed in %s\n", verbs[acl->verb], acl_name); + HDEBUG(D_acl) debug_printf_indent("%s: condition test failed in %s\n", verbs[acl->verb], acl_name); break; /* DISCARD and DROP can happen only from a nested ACL condition, and DISCARD can happen only for an "accept" or "discard" verb. */ case DISCARD: - HDEBUG(D_acl) debug_printf("%s: condition test yielded \"discard\" in %s\n", + HDEBUG(D_acl) debug_printf_indent("%s: condition test yielded \"discard\" in %s\n", verbs[acl->verb], acl_name); break; case FAIL_DROP: - HDEBUG(D_acl) debug_printf("%s: condition test yielded \"drop\" in %s\n", + HDEBUG(D_acl) debug_printf_indent("%s: condition test yielded \"drop\" in %s\n", verbs[acl->verb], acl_name); break; } @@ -4055,12 +4053,12 @@ while (acl != NULL) case ACL_ACCEPT: if (cond == OK || cond == DISCARD) { - HDEBUG(D_acl) debug_printf("end of %s: ACCEPT\n", acl_name); + HDEBUG(D_acl) debug_printf_indent("end of %s: ACCEPT\n", acl_name); return cond; } if (endpass_seen) { - HDEBUG(D_acl) debug_printf("accept: endpass encountered - denying access\n"); + HDEBUG(D_acl) debug_printf_indent("accept: endpass encountered - denying access\n"); return cond; } break; @@ -4068,7 +4066,7 @@ while (acl != NULL) case ACL_DEFER: if (cond == OK) { - HDEBUG(D_acl) debug_printf("end of %s: DEFER\n", acl_name); + HDEBUG(D_acl) debug_printf_indent("end of %s: DEFER\n", acl_name); if (acl_quit_check) goto badquit; acl_temp_details = TRUE; return DEFER; @@ -4078,7 +4076,7 @@ while (acl != NULL) case ACL_DENY: if (cond == OK) { - HDEBUG(D_acl) debug_printf("end of %s: DENY\n", acl_name); + HDEBUG(D_acl) debug_printf_indent("end of %s: DENY\n", acl_name); if (acl_quit_check) goto badquit; return FAIL; } @@ -4087,13 +4085,13 @@ while (acl != NULL) case ACL_DISCARD: if (cond == OK || cond == DISCARD) { - HDEBUG(D_acl) debug_printf("end of %s: DISCARD\n", acl_name); + HDEBUG(D_acl) debug_printf_indent("end of %s: DISCARD\n", acl_name); if (acl_quit_check) goto badquit; return DISCARD; } if (endpass_seen) { - HDEBUG(D_acl) debug_printf("discard: endpass encountered - denying access\n"); + HDEBUG(D_acl) debug_printf_indent("discard: endpass encountered - denying access\n"); return cond; } break; @@ -4101,7 +4099,7 @@ while (acl != NULL) case ACL_DROP: if (cond == OK) { - HDEBUG(D_acl) debug_printf("end of %s: DROP\n", acl_name); + HDEBUG(D_acl) debug_printf_indent("end of %s: DROP\n", acl_name); if (acl_quit_check) goto badquit; return FAIL_DROP; } @@ -4110,7 +4108,7 @@ while (acl != NULL) case ACL_REQUIRE: if (cond != OK) { - HDEBUG(D_acl) debug_printf("end of %s: not OK\n", acl_name); + HDEBUG(D_acl) debug_printf_indent("end of %s: not OK\n", acl_name); if (acl_quit_check) goto badquit; return cond; } @@ -4140,7 +4138,7 @@ while (acl != NULL) /* We have reached the end of the ACL. This is an implicit DENY. */ -HDEBUG(D_acl) debug_printf("end of %s: implicit DENY\n", acl_name); +HDEBUG(D_acl) debug_printf_indent("end of %s: implicit DENY\n", acl_name); return FAIL; badquit: @@ -4156,7 +4154,7 @@ badquit: the name of an ACL followed optionally by up to 9 space-separated arguments. The name and args are separately expanded. Args go into $acl_arg globals. */ static int -acl_check_wargs(int where, address_item *addr, const uschar *s, int level, +acl_check_wargs(int where, address_item *addr, const uschar *s, uschar **user_msgptr, uschar **log_msgptr) { uschar * tmp; @@ -4194,7 +4192,9 @@ while (i < 9) acl_arg[i++] = NULL; } -ret = acl_check_internal(where, addr, name, level, user_msgptr, log_msgptr); +acl_level++; +ret = acl_check_internal(where, addr, name, user_msgptr, log_msgptr); +acl_level--; acl_narg = sav_narg; for (i = 0; i < 9; i++) acl_arg[i] = sav_arg[i]; @@ -4219,6 +4219,7 @@ acl_eval(int where, uschar *s, uschar **user_msgptr, uschar **log_msgptr) { address_item adb; address_item *addr = NULL; +int rc; *user_msgptr = *log_msgptr = NULL; sender_verified_failed = NULL; @@ -4236,7 +4237,10 @@ if (where == ACL_WHERE_RCPT) addr->lc_local_part = deliver_localpart; } -return acl_check_internal(where, addr, s, 0, user_msgptr, log_msgptr); +acl_level++; +rc = acl_check_internal(where, addr, s, user_msgptr, log_msgptr); +acl_level--; +return rc; } @@ -4300,7 +4304,9 @@ if (where==ACL_WHERE_RCPT || where==ACL_WHERE_VRFY) } acl_where = where; -rc = acl_check_internal(where, addr, s, 0, user_msgptr, log_msgptr); +acl_level = 0; +rc = acl_check_internal(where, addr, s, user_msgptr, log_msgptr); +acl_level = 0; acl_where = ACL_WHERE_UNKNOWN; /* Cutthrough - if requested, @@ -4347,7 +4353,7 @@ switch (where) } else { - HDEBUG(D_acl) debug_printf("cutthrough defer; will spool\n"); + HDEBUG(D_acl) debug_printf_indent("cutthrough defer; will spool\n"); rc = OK; } break; diff --git a/src/src/debug.c b/src/src/debug.c index 8f9359b15..3cd6d0c92 100644 --- a/src/src/debug.c +++ b/src/src/debug.c @@ -137,7 +137,7 @@ debug_printf("%s uid=%ld gid=%ld euid=%ld egid=%ld\n", s, *************************************************/ /* There are two entries, one for use when being called directly from a -function with a variable argument list. +function with a variable argument list, one for prepending an indent. If debug_pid is nonzero, print the pid at the start of each line. This is for tidier output when running parallel remote deliveries with debugging turned on. @@ -146,6 +146,28 @@ get interleaved. Since some calls to debug_printf() don't end with newline, we save up the text until we do get the newline. Take care to not disturb errno. */ + +/* Debug printf indented by ACL nest depth */ +void +debug_printf_indent(const char * format, ...) +{ +va_list ap; +unsigned depth = acl_level + expand_level, i; + +if (!debug_file) return; +if (depth > 0) + { + for (i = depth >> 2; i > 0; i--) + fprintf(debug_file, " ."); + fprintf(debug_file, "%*s", depth & 3, ""); + } + +va_start(ap, format); +debug_vprintf(format, ap); +va_end(ap); +} + + void debug_printf(const char *format, ...) { diff --git a/src/src/expand.c b/src/src/expand.c index d2fcd2358..55fb0b875 100644 --- a/src/src/expand.c +++ b/src/src/expand.c @@ -2099,7 +2099,7 @@ while (i < nsub) } DEBUG(D_expand) - debug_printf("expanding: acl: %s arg: %s%s\n", + debug_printf_indent("expanding: acl: %s arg: %s%s\n", sub[0], acl_narg>0 ? acl_arg[0] : US"<none>", acl_narg>1 ? " +more" : ""); @@ -2523,7 +2523,7 @@ switch(cond_type) { num[i] = 0; DEBUG(D_expand) - debug_printf("empty string cast to zero for numerical comparison\n"); + debug_printf_indent("empty string cast to zero for numerical comparison\n"); } else { @@ -2832,7 +2832,7 @@ switch(cond_type) uschar *save_iterate_item = iterate_item; int (*compare)(const uschar *, const uschar *); - DEBUG(D_expand) debug_printf("condition: %s\n", name); + DEBUG(D_expand) debug_printf_indent("condition: %s\n", name); tempcond = FALSE; compare = cond_type == ECOND_INLISTI @@ -2920,7 +2920,7 @@ switch(cond_type) int sep = 0; uschar *save_iterate_item = iterate_item; - DEBUG(D_expand) debug_printf("condition: %s\n", name); + DEBUG(D_expand) debug_printf_indent("condition: %s\n", name); while (isspace(*s)) s++; if (*s++ != '{') goto COND_FAILED_CURLY_START; /* }-for-text-editors */ @@ -2959,7 +2959,7 @@ switch(cond_type) list = sub[0]; while ((iterate_item = string_nextinlist(&list, &sep, NULL, 0)) != NULL) { - DEBUG(D_expand) debug_printf("%s: $item = \"%s\"\n", name, iterate_item); + DEBUG(D_expand) debug_printf_indent("%s: $item = \"%s\"\n", name, iterate_item); if (!eval_condition(sub[1], resetok, &tempcond)) { expand_string_message = string_sprintf("%s inside \"%s\" condition", @@ -2967,7 +2967,7 @@ switch(cond_type) iterate_item = save_iterate_item; return NULL; } - DEBUG(D_expand) debug_printf("%s: condition evaluated to %s\n", name, + DEBUG(D_expand) debug_printf_indent("%s: condition evaluated to %s\n", name, tempcond? "true":"false"); if (yield != NULL) *yield = (tempcond == testfor); @@ -3024,7 +3024,7 @@ switch(cond_type) } } DEBUG(D_expand) - debug_printf("considering %s: %s\n", ourname, len ? t : US"<empty>"); + debug_printf_indent("considering %s: %s\n", ourname, len ? t : US"<empty>"); /* logic for the lax case from expand_check_condition(), which also does expands, and the logic is both short and stable enough that there should be no maintenance burden from replicating it. */ @@ -3051,7 +3051,7 @@ switch(cond_type) "value \"%s\"", t); return NULL; } - DEBUG(D_expand) debug_printf("%s: condition evaluated to %s\n", ourname, + DEBUG(D_expand) debug_printf_indent("%s: condition evaluated to %s\n", ourname, boolvalue? "true":"false"); if (yield != NULL) *yield = (boolvalue == testfor); return s; @@ -3447,7 +3447,7 @@ hash_source = string_catn(hash_source, &size, &offset, daystamp, 3); hash_source = string_cat(hash_source, &size, &offset, address); hash_source[offset] = '\0'; -DEBUG(D_expand) debug_printf("prvs: hash source is '%s'\n", hash_source); +DEBUG(D_expand) debug_printf_indent("prvs: hash source is '%s'\n", hash_source); memset(innerkey, 0x36, 64); memset(outerkey, 0x5c, 64); @@ -3870,8 +3870,9 @@ uschar *save_expand_nstring[EXPAND_MAXN+1]; int save_expand_nlength[EXPAND_MAXN+1]; BOOL resetok = TRUE; +expand_level++; DEBUG(D_expand) - debug_printf("%s: %s\n", skipping ? " scanning" : "considering", string); + debug_printf_indent("/%s: %s\n", skipping ? " scanning" : "considering", string); expand_string_forcedfail = FALSE; expand_string_message = US""; @@ -4086,7 +4087,7 @@ while (*s != 0) case OK: case FAIL: DEBUG(D_expand) - debug_printf("acl expansion yield: %s\n", user_msg); + debug_printf_indent("acl expansion yield: %s\n", user_msg); if (user_msg) yield = string_cat(yield, &size, &ptr, user_msg); continue; @@ -4117,9 +4118,10 @@ while (*s != 0) if (next_s == NULL) goto EXPAND_FAILED; /* message already set */ DEBUG(D_expand) - debug_printf(" condition: %.*s\n result: %s\n", - (int)(next_s - s), s, - cond ? "true" : "false"); + { + debug_printf_indent("|__condition: %.*s\n", (int)(next_s - s), s); + debug_printf_indent("|_____result: %s\n", cond ? "true" : "false"); + } s = next_s; @@ -4576,11 +4578,11 @@ while (*s != 0) uschar *hash = string_copyn(expand_nstring[3],expand_nlength[3]); uschar *domain = string_copyn(expand_nstring[5],expand_nlength[5]); - DEBUG(D_expand) debug_printf("prvscheck localpart: %s\n", local_part); - DEBUG(D_expand) debug_printf("prvscheck key number: %s\n", key_num); - DEBUG(D_expand) debug_printf("prvscheck daystamp: %s\n", daystamp); - DEBUG(D_expand) debug_printf("prvscheck hash: %s\n", hash); - DEBUG(D_expand) debug_printf("prvscheck domain: %s\n", domain); + DEBUG(D_expand) debug_printf_indent("prvscheck localpart: %s\n", local_part); + DEBUG(D_expand) debug_printf_indent("prvscheck key number: %s\n", key_num); + DEBUG(D_expand) debug_printf_indent("prvscheck daystamp: %s\n", daystamp); + DEBUG(D_expand) debug_printf_indent("prvscheck hash: %s\n", hash); + DEBUG(D_expand) debug_printf_indent("prvscheck domain: %s\n", domain); /* Set up expansion variables */ prvscheck_address = string_cat (NULL, &mysize, &myptr, local_part); @@ -4608,8 +4610,8 @@ while (*s != 0) goto EXPAND_FAILED; } - DEBUG(D_expand) debug_printf("prvscheck: received hash is %s\n", hash); - DEBUG(D_expand) debug_printf("prvscheck: own hash is %s\n", p); + DEBUG(D_expand) debug_printf_indent("prvscheck: received hash is %s\n", hash); + DEBUG(D_expand) debug_printf_indent("prvscheck: own hash is %s\n", p); if (Ustrcmp(p,hash) == 0) { @@ -4627,18 +4629,18 @@ while (*s != 0) if (iexpire >= inow) { prvscheck_result = US"1"; - DEBUG(D_expand) debug_printf("prvscheck: success, $pvrs_result set to 1\n"); + DEBUG(D_expand) debug_printf_indent("prvscheck: success, $pvrs_result set to 1\n"); } else { prvscheck_result = NULL; - DEBUG(D_expand) debug_printf("prvscheck: signature expired, $pvrs_result unset\n"); + DEBUG(D_expand) debug_printf_indent("prvscheck: signature expired, $pvrs_result unset\n"); } } else { prvscheck_result = NULL; - DEBUG(D_expand) debug_printf("prvscheck: hash failure, $pvrs_result unset\n"); + DEBUG(D_expand) debug_printf_indent("prvscheck: hash failure, $pvrs_result unset\n"); } /* Now expand the final argument. We leave this till now so that @@ -4841,7 +4843,7 @@ while (*s != 0) } } - DEBUG(D_expand) debug_printf("connected to socket %s\n", sub_arg[0]); + DEBUG(D_expand) debug_printf_indent("connected to socket %s\n", sub_arg[0]); /* Allow sequencing of test actions */ if (running_in_test_harness) millisleep(100); @@ -4851,7 +4853,7 @@ while (*s != 0) if (sub_arg[1][0] != 0) { int len = Ustrlen(sub_arg[1]); - DEBUG(D_expand) debug_printf("writing \"%s\" to socket\n", + DEBUG(D_expand) debug_printf_indent("writing \"%s\" to socket\n", sub_arg[1]); if (write(fd, sub_arg[1], len) != len) { @@ -5803,7 +5805,7 @@ while (*s != 0) { *outsep = (uschar)sep; /* Separator as a string */ - DEBUG(D_expand) debug_printf("%s: $item = \"%s\"\n", name, iterate_item); + DEBUG(D_expand) debug_printf_indent("%s: $item = \"%s\"\n", name, iterate_item); if (item_type == EITEM_FILTER) { @@ -5816,7 +5818,7 @@ while (*s != 0) expand_string_message, name); goto EXPAND_FAILED; } - DEBUG(D_expand) debug_printf("%s: condition is %s\n", name, + DEBUG(D_expand) debug_printf_indent("%s: condition is %s\n", name, condresult? "true":"false"); if (condresult) temp = iterate_item; /* TRUE => include this item */ @@ -5971,7 +5973,7 @@ while (*s != 0) uschar * newkeylist = NULL; uschar * srcfield; - DEBUG(D_expand) debug_printf("%s: $item = \"%s\"\n", name, srcitem); + DEBUG(D_expand) debug_printf_indent("%s: $item = \"%s\"\n", name, srcitem); /* extract field for comparisons */ iterate_item = srcitem; @@ -6000,7 +6002,7 @@ while (*s != 0) /* build and run condition string */ expr = string_sprintf("%s{%s}{%s}", cmp, srcfield, dstfield); - DEBUG(D_expand) debug_printf("%s: cond = \"%s\"\n", name, expr); + DEBUG(D_expand) debug_printf_indent("%s: cond = \"%s\"\n", name, expr); if (!eval_condition(expr, &resetok, &before)) { expand_string_message = string_sprintf("comparison in sort: %s", @@ -6045,8 +6047,8 @@ while (*s != 0) dstlist = newlist; dstkeylist = newkeylist; - DEBUG(D_expand) debug_printf("%s: dstlist = \"%s\"\n", name, dstlist); - DEBUG(D_expand) debug_printf("%s: dstkeylist = \"%s\"\n", name, dstkeylist); + DEBUG(D_expand) debug_printf_indent("%s: dstlist = \"%s\"\n", name, dstlist); + DEBUG(D_expand) debug_printf_indent("%s: dstkeylist = \"%s\"\n", name, dstkeylist); } if (dstlist) @@ -7095,7 +7097,7 @@ while (*s != 0) goto EXPAND_FAILED; } yield = string_cat(yield, &size, &ptr, s); - DEBUG(D_expand) debug_printf("yield: '%s'\n", yield); + DEBUG(D_expand) debug_printf_indent("yield: '%s'\n", yield); continue; } @@ -7489,10 +7491,11 @@ else if (resetok_p) *resetok_p = FALSE; DEBUG(D_expand) { - debug_printf(" expanding: %.*s\n result: %s\n", (int)(s - string), string, - yield); - if (skipping) debug_printf(" skipping: result is not used\n"); + debug_printf_indent("|__expanding: %.*s\n", (int)(s - string), string); + debug_printf_indent("%s_____result: %s\n", skipping ? "|" : "\\", yield); + if (skipping) debug_printf_indent("\\___skipping: result is not used\n"); } +expand_level--; return yield; /* This is the failure exit: easiest to program with a goto. We still need @@ -7514,11 +7517,13 @@ EXPAND_FAILED: if (left != NULL) *left = s; DEBUG(D_expand) { - debug_printf("failed to expand: %s\n", string); - debug_printf(" error message: %s\n", expand_string_message); - if (expand_string_forcedfail) debug_printf("failure was forced\n"); + debug_printf_indent("|failed to expand: %s\n", string); + debug_printf_indent("%s___error message: %s\n", + expand_string_forcedfail ? "|" : "\\", expand_string_message); + if (expand_string_forcedfail) debug_printf_indent("\\failure was forced\n"); } if (resetok_p) *resetok_p = resetok; +expand_level--; return NULL; } @@ -7645,7 +7650,7 @@ if (isspace(*s)) if (*s == '\0') { DEBUG(D_expand) - debug_printf("treating blank string as number 0\n"); + debug_printf_indent("treating blank string as number 0\n"); return 0; } } diff --git a/src/src/functions.h b/src/src/functions.h index 790d8faf7..0fc69e4eb 100644 --- a/src/src/functions.h +++ b/src/src/functions.h @@ -95,6 +95,7 @@ extern int auth_call_saslauthd(const uschar *, const uschar *, extern int auth_check_serv_cond(auth_instance *); extern int auth_check_some_cond(auth_instance *, uschar *, uschar *, int); + extern int auth_get_data(uschar **, uschar *, int); extern int auth_get_no64_data(uschar **, uschar *); extern uschar *auth_xtextencode(uschar *, int); @@ -131,6 +132,7 @@ extern void debug_logging_activate(uschar *, uschar *); extern void debug_logging_stop(void); extern void debug_print_argv(const uschar **); extern void debug_print_ids(uschar *); +extern void debug_printf_indent(const char *, ...) PRINTF_FUNCTION(1,2); extern void debug_print_string(uschar *); extern void debug_print_tree(tree_node *); extern void debug_vprintf(const char *, va_list); diff --git a/src/src/globals.c b/src/src/globals.c index bab135dba..5e0fc2387 100644 --- a/src/src/globals.c +++ b/src/src/globals.c @@ -228,6 +228,8 @@ uschar *acl_arg[9] = {NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL}; int acl_narg = 0; +int acl_level = 0; + uschar *acl_not_smtp = NULL; #ifdef WITH_CONTENT_SCAN uschar *acl_not_smtp_mime = NULL; @@ -713,6 +715,7 @@ uschar *exim_path = US BIN_DIRECTORY "/exim" "\0<---------------Space to patch exim_path->"; uid_t exim_uid = EXIM_UID; BOOL exim_uid_set = TRUE; /* This uid is always set */ +int expand_level = 0; /* Nesting depth, indent for debug */ int expand_forbid = 0; int expand_nlength[EXPAND_MAXN+1]; int expand_nmax = -1; diff --git a/src/src/globals.h b/src/src/globals.h index 4e1e0ca7b..c2c69cf7c 100644 --- a/src/src/globals.h +++ b/src/src/globals.h @@ -160,6 +160,7 @@ extern header_line *acl_added_headers; /* Headers added by an ACL */ extern tree_node *acl_anchor; /* Tree of named ACLs */ extern uschar *acl_arg[9]; /* Argument to ACL call */ extern int acl_narg; /* Number of arguments to ACL call */ +extern int acl_level; /* Nesting depth and debug indent */ extern uschar *acl_not_smtp; /* ACL run for non-SMTP messages */ #ifdef WITH_CONTENT_SCAN extern uschar *acl_not_smtp_mime; /* For MIME parts of ditto */ @@ -442,6 +443,7 @@ extern uschar *exim_path; /* Path to exec exim */ extern const uschar *exim_sieve_extension_list[]; /* list of sieve extensions */ extern uid_t exim_uid; /* Non-root uid for exim */ extern BOOL exim_uid_set; /* TRUE if exim_uid set */ +extern int expand_level; /* Nesting depth; indent for debug */ extern int expand_forbid; /* RDO flags for forbidding things */ extern int expand_nlength[]; /* Lengths of numbered strings */ extern int expand_nmax; /* Max numerical value */ diff --git a/src/src/malware.c b/src/src/malware.c index e1eff16cf..547bc26e6 100644 --- a/src/src/malware.c +++ b/src/src/malware.c @@ -231,13 +231,13 @@ while ((rcv = read(fd, p, 1)) > 0) } if (!ok) { - DEBUG(D_acl) debug_printf("Malware scan: read %s (%s)\n", + DEBUG(D_acl) debug_printf_indent("Malware scan: read %s (%s)\n", rcv==0 ? "EOF" : "error", strerror(errno)); return rcv==0 ? -1 : -2; } *p = '\0'; -DEBUG(D_acl) debug_printf("Malware scan: read '%s'\n", buffer); +DEBUG(D_acl) debug_printf_indent("Malware scan: read '%s'\n", buffer); return p - buffer; } @@ -475,7 +475,7 @@ if (*av_scanner == '$') expand_string_message)); DEBUG(D_acl) - debug_printf("Expanded av_scanner global: %s\n", av_scanner_work); + debug_printf_indent("Expanded av_scanner global: %s\n", av_scanner_work); /* disable result caching in this case */ malware_name = NULL; malware_ok = FALSE; @@ -512,7 +512,7 @@ if (!malware_ok) return m_errlog_defer(scanent, CUS callout_address, errstr); break; } - DEBUG(D_acl) debug_printf("Malware scan: %s tmo %s\n", scanner_name, readconf_printtime(timeout)); + DEBUG(D_acl) debug_printf_indent("Malware scan: %s tmo %s\n", scanner_name, readconf_printtime(timeout)); switch (scanent->scancode) { @@ -535,7 +535,7 @@ if (!malware_ok) par_count++; } scanrequest = string_sprintf("%s HTTP/1.0\r\n\r\n", scanrequest); - DEBUG(D_acl) debug_printf("Malware scan: issuing %s: %s\n", + DEBUG(D_acl) debug_printf_indent("Malware scan: issuing %s: %s\n", scanner_name, scanrequest); /* send scan request */ @@ -615,7 +615,7 @@ if (!malware_ok) drweb_slen = htonl(fsize); lseek(drweb_fd, 0, SEEK_SET); - DEBUG(D_acl) debug_printf("Malware scan: issuing %s remote scan [%s]\n", + DEBUG(D_acl) debug_printf_indent("Malware scan: issuing %s remote scan [%s]\n", scanner_name, scanner_options); /* send scan request */ @@ -664,7 +664,7 @@ if (!malware_ok) { drweb_slen = htonl(Ustrlen(eml_filename)); - DEBUG(D_acl) debug_printf("Malware scan: issuing %s local scan [%s]\n", + DEBUG(D_acl) debug_printf_indent("Malware scan: issuing %s local scan [%s]\n", scanner_name, scanner_options); /* send scan request */ @@ -782,7 +782,7 @@ if (!malware_ok) eml_filename); /* and send it */ - DEBUG(D_acl) debug_printf("Malware scan: issuing %s %s\n", + DEBUG(D_acl) debug_printf_indent("Malware scan: issuing %s %s\n", scanner_name, buf); if (m_sock_send(sock, buf, Ustrlen(buf), &errstr) < 0) return m_errlog_defer(scanent, CUS callout_address, errstr); @@ -842,7 +842,7 @@ if (!malware_ok) malware_name = NULL; - DEBUG(D_acl) debug_printf("Malware scan: issuing %s scan [%s]\n", + DEBUG(D_acl) debug_printf_indent("Malware scan: issuing %s scan [%s]\n", scanner_name, scanner_options); /* pass options */ memset(av_buffer, 0, sizeof(av_buffer)); @@ -938,7 +938,7 @@ if (!malware_ok) if (p) *p = '\0'; - DEBUG(D_acl) debug_printf("Malware scan: issuing %s scan [%s]\n", + DEBUG(D_acl) debug_printf_indent("Malware scan: issuing %s scan [%s]\n", scanner_name, scanner_options); /* send scan request */ @@ -1069,7 +1069,7 @@ if (!malware_ok) /* redirect STDERR too */ commandline = string_sprintf("%s 2>&1", commandline); - DEBUG(D_acl) debug_printf("Malware scan: issuing %s scan [%s]\n", + DEBUG(D_acl) debug_printf_indent("Malware scan: issuing %s scan [%s]\n", scanner_name, commandline); /* store exims signal handlers */ @@ -1172,7 +1172,7 @@ if (!malware_ok) if ((p = Ustrrchr(file_name, '/'))) *p = '\0'; - DEBUG(D_acl) debug_printf("Malware scan: issuing %s scan [%s]\n", + DEBUG(D_acl) debug_printf_indent("Malware scan: issuing %s scan [%s]\n", scanner_name, scanner_options); if ( write(sock, file_name, Ustrlen(file_name)) < 0 @@ -1346,7 +1346,7 @@ if (!malware_ok) int i = random_number( num_servers ); clamd_address * cd = cv[i]; - DEBUG(D_acl) debug_printf("trying server name %s, port %u\n", + DEBUG(D_acl) debug_printf_indent("trying server name %s, port %u\n", cd->hostspec, cd->tcp_port); /* Lookup the host. This is to ensure that we connect to the same IP @@ -1402,7 +1402,7 @@ if (!malware_ok) * that port on a second connection; then in the scan-method-neutral * part, read the response back on the original connection. */ - DEBUG(D_acl) debug_printf( + DEBUG(D_acl) debug_printf_indent( "Malware scan: issuing %s old-style remote scan (PORT)\n", scanner_name); @@ -1444,7 +1444,7 @@ if (!malware_ok) chunks, <n> a 4-byte number (network order), terminated by a zero-length chunk. */ - DEBUG(D_acl) debug_printf( + DEBUG(D_acl) debug_printf_indent( "Malware scan: issuing %s new-style remote scan (zINSTREAM)\n", scanner_name); @@ -1555,7 +1555,7 @@ if (!malware_ok) /* Pass the string to ClamAV (7 = "SCAN \n" + \0) */ file_name = string_sprintf("SCAN %s\n", eml_filename); - DEBUG(D_acl) debug_printf( + DEBUG(D_acl) debug_printf_indent( "Malware scan: issuing %s local-path scan [%s]\n", scanner_name, scanner_options); @@ -1616,7 +1616,7 @@ if (!malware_ok) p = av_buffer + Ustrlen(av_buffer) - 1; if (*p == '\n') *p = '\0'; - DEBUG(D_acl) debug_printf("Malware response: %s\n", av_buffer); + DEBUG(D_acl) debug_printf_indent("Malware response: %s\n", av_buffer); while (isspace(*--p) && (p > av_buffer)) *p = '\0'; @@ -1653,7 +1653,7 @@ if (!malware_ok) *p = '\0'; } malware_name = string_copy(vname); - DEBUG(D_acl) debug_printf("Malware found, name \"%s\"\n", malware_name); + DEBUG(D_acl) debug_printf_indent("Malware found, name \"%s\"\n", malware_name); } else if (Ustrcmp(result_tag, "ERROR") == 0) @@ -1664,7 +1664,7 @@ if (!malware_ok) { /* Everything should be OK */ malware_name = NULL; - DEBUG(D_acl) debug_printf("Malware not found\n"); + DEBUG(D_acl) debug_printf_indent("Malware not found\n"); } else @@ -1770,7 +1770,7 @@ if (!malware_ok) malware_name = NULL; - DEBUG(D_acl) debug_printf("Malware scan: issuing %s scan\n", scanner_name); + DEBUG(D_acl) debug_printf_indent("Malware scan: issuing %s scan\n", scanner_name); if ((retval = mksd_scan_packed(scanent, sock, eml_filename, tmo)) != OK) { @@ -1812,7 +1812,7 @@ if (!malware_ok) int slen = Ustrlen(buf); if (slen >= 1) { - DEBUG(D_acl) debug_printf("got from avast: %s\n", buf); + DEBUG(D_acl) debug_printf_indent("got from avast: %s\n", buf); switch (avast_stage) { case AVA_HELO: @@ -1923,7 +1923,7 @@ if (!malware_ok) /* match virus name against pattern (caseless ------->----------v) */ if (malware_name && regex_match_and_setup(re, malware_name, 0, -1)) { - DEBUG(D_acl) debug_printf( + DEBUG(D_acl) debug_printf_indent( "Matched regex to malware [%s] [%s]\n", malware_re, malware_name); return OK; } diff --git a/src/src/mime.c b/src/src/mime.c index 5ed15b081..821cb541d 100644 --- a/src/src/mime.c +++ b/src/src/mime.c @@ -446,7 +446,7 @@ uschar * s = *sp; uschar * val = NULL; int size = 0, ptr = 0; -/* debug_printf(" considering paramval '%s'\n", s); */ +/* debug_printf_indent(" considering paramval '%s'\n", s); */ while (*s && *s != ';') /* ; terminates */ if (*s == '"') @@ -545,7 +545,7 @@ while(1) if (!fgets(CS header, MIME_MAX_HEADER_SIZE, f)) { /* Hit EOF or read error. Ugh. */ - DEBUG(D_acl) debug_printf("MIME: Hit EOF ...\n"); + DEBUG(D_acl) debug_printf_indent("MIME: Hit EOF ...\n"); return rc; } @@ -557,12 +557,12 @@ while(1) if (Ustrncmp((header+2+Ustrlen(context->boundary)), "--", 2) == 0) { /* END boundary found */ - DEBUG(D_acl) debug_printf("MIME: End boundary found %s\n", + DEBUG(D_acl) debug_printf_indent("MIME: End boundary found %s\n", context->boundary); return rc; } - DEBUG(D_acl) debug_printf("MIME: Next part with boundary %s\n", + DEBUG(D_acl) debug_printf_indent("MIME: Next part with boundary %s\n", context->boundary); break; } @@ -586,7 +586,7 @@ while(1) for (q = p; *q != ';' && *q; q++) ; *mh->value = string_copynlc(p, q-p); - DEBUG(D_acl) debug_printf("MIME: found %s header, value is '%s'\n", + DEBUG(D_acl) debug_printf_indent("MIME: found %s header, value is '%s'\n", mh->name, *mh->value); if (*(p = q)) p++; /* jump past the ; */ @@ -604,7 +604,7 @@ while(1) { mime_parameter * mp; - DEBUG(D_acl) debug_printf("MIME: considering paramlist '%s'\n", p); + DEBUG(D_acl) debug_printf_indent("MIME: considering paramlist '%s'\n", p); if ( !mime_filename && strncmpic(CUS"content-disposition:", header, 20) == 0 @@ -649,15 +649,15 @@ while(1) else p = q; - DEBUG(D_acl) debug_printf("MIME: charset %s fname '%s'\n", + DEBUG(D_acl) debug_printf_indent("MIME: charset %s fname '%s'\n", mime_filename_charset ? mime_filename_charset : US"<NULL>", p); temp_string = rfc2231_to_2047(p, mime_filename_charset, &slen); - DEBUG(D_acl) debug_printf("MIME: 2047-name %s\n", temp_string); + DEBUG(D_acl) debug_printf_indent("MIME: 2047-name %s\n", temp_string); temp_string = rfc2047_decode(temp_string, FALSE, NULL, ' ', NULL, &err_msg); - DEBUG(D_acl) debug_printf("MIME: plain-name %s\n", temp_string); + DEBUG(D_acl) debug_printf_indent("MIME: plain-name %s\n", temp_string); size = Ustrlen(temp_string); @@ -692,7 +692,7 @@ while(1) ? rfc2047_decode(q, check_rfc2047_length, NULL, 32, NULL, &dummy_errstr) : NULL; - DEBUG(D_acl) debug_printf( + DEBUG(D_acl) debug_printf_indent( "MIME: found %s parameter in %s header, value '%s'\n", mp->name, mh->name, *mp->value); @@ -710,7 +710,7 @@ while(1) { if (decoding_failed) mime_filename = mime_fname_rfc2231; - DEBUG(D_acl) debug_printf( + DEBUG(D_acl) debug_printf_indent( "MIME: found %s parameter in %s header, value is '%s'\n", "filename", mh->name, mime_filename); } @@ -753,7 +753,7 @@ while(1) (Ustrncmp(mime_content_type,"multipart",9) == 0) ) { DEBUG(D_acl) - debug_printf("MIME: Entering multipart recursion, boundary '%s'\n", + debug_printf_indent("MIME: Entering multipart recursion, boundary '%s'\n", nested_context.boundary); nested_context.context = diff --git a/src/src/pdkim/rsa.c b/src/src/pdkim/rsa.c index aeb016ce5..548bae6be 100644 --- a/src/src/pdkim/rsa.c +++ b/src/src/pdkim/rsa.c @@ -170,7 +170,7 @@ uschar tag_class; int taglen; long tag, len; -/* debug_printf("as_tag: %02x %02x %02x %02x\n", +/* acl_debug_printf("as_tag: %02x %02x %02x %02x\n", der->data[0], der->data[1], der->data[2], der->data[3]); */ if ((rc = asn1_get_tag_der(der->data++, der->len--, &tag_class, &taglen, &tag)) @@ -183,7 +183,7 @@ if ((len = asn1_get_length_der(der->data, der->len, &taglen)) < 0) return ASN1_DER_ERROR; if (alen) *alen = len; -/* debug_printf("as_tag: tlen %d dlen %d\n", taglen, (int)len); */ +/* acl_debug_printf("as_tag: tlen %d dlen %d\n", taglen, (int)len); */ der->data += taglen; der->len -= taglen; @@ -325,25 +325,25 @@ if ( (s1 = as_mpi(&der, &sign_ctx->n)) ) return s1; -DEBUG(D_acl) debug_printf("rsa_signing_init:\n"); +DEBUG(D_acl) acl_debug_printf("rsa_signing_init:\n"); { uschar * s; gcry_mpi_aprint (GCRYMPI_FMT_HEX, &s, NULL, sign_ctx->n); - debug_printf(" N : %s\n", s); + acl_debug_printf(" N : %s\n", s); gcry_mpi_aprint (GCRYMPI_FMT_HEX, &s, NULL, sign_ctx->e); - debug_printf(" E : %s\n", s); + acl_debug_printf(" E : %s\n", s); gcry_mpi_aprint (GCRYMPI_FMT_HEX, &s, NULL, sign_ctx->d); - debug_printf(" D : %s\n", s); + acl_debug_printf(" D : %s\n", s); gcry_mpi_aprint (GCRYMPI_FMT_HEX, &s, NULL, sign_ctx->p); - debug_printf(" P : %s\n", s); + acl_debug_printf(" P : %s\n", s); gcry_mpi_aprint (GCRYMPI_FMT_HEX, &s, NULL, sign_ctx->q); - debug_printf(" Q : %s\n", s); + acl_debug_printf(" Q : %s\n", s); gcry_mpi_aprint (GCRYMPI_FMT_HEX, &s, NULL, sign_ctx->dp); - debug_printf(" DP: %s\n", s); + acl_debug_printf(" DP: %s\n", s); gcry_mpi_aprint (GCRYMPI_FMT_HEX, &s, NULL, sign_ctx->dq); - debug_printf(" DQ: %s\n", s); + acl_debug_printf(" DQ: %s\n", s); gcry_mpi_aprint (GCRYMPI_FMT_HEX, &s, NULL, sign_ctx->qp); - debug_printf(" QP: %s\n", s); + acl_debug_printf(" QP: %s\n", s); } return NULL; @@ -402,13 +402,13 @@ DEBUG(D_acl) { uschar * s; gcry_mpi_aprint (GCRYMPI_FMT_HEX, &s, NULL, m_sig); - debug_printf(" SG: %s\n", s); + acl_debug_printf(" SG: %s\n", s); } gerr = gcry_mpi_print(GCRYMPI_FMT_USG, sig->data, SIGSPACE, &sig->len, m_sig); if (gerr) { - debug_printf("signature conversion from MPI to buffer failed\n"); + acl_debug_printf("signature conversion from MPI to buffer failed\n"); return US gcry_strerror(gerr); } #undef SIGSPACE @@ -480,13 +480,13 @@ if ( (errstr = as_mpi(pubkey_der, &verify_ctx->n)) ) return errstr; -DEBUG(D_acl) debug_printf("rsa_verify_init:\n"); +DEBUG(D_acl) acl_debug_printf("rsa_verify_init:\n"); { uschar * s; gcry_mpi_aprint (GCRYMPI_FMT_HEX, &s, NULL, verify_ctx->n); - debug_printf(" N : %s\n", s); + acl_debug_printf(" N : %s\n", s); gcry_mpi_aprint (GCRYMPI_FMT_HEX, &s, NULL, verify_ctx->e); - debug_printf(" E : %s\n", s); + acl_debug_printf(" E : %s\n", s); } return NULL; @@ -528,7 +528,7 @@ if ( (stage = US"pkey sexp build", gerr = gcry_pk_verify (s_sig, s_hash, s_pkey)) ) { - DEBUG(D_acl) debug_printf("verify: error in stage '%s'\n", stage); + DEBUG(D_acl) acl_debug_printf("verify: error in stage '%s'\n", stage); return US gcry_strerror(gerr); } diff --git a/src/src/receive.c b/src/src/receive.c index 67fcc8e15..f98eab18c 100644 --- a/src/src/receive.c +++ b/src/src/receive.c @@ -1116,7 +1116,7 @@ switch(where) if (acl_removed_headers != NULL) { - DEBUG(D_receive|D_acl) debug_printf(">>Headers removed by %s ACL:\n", acl_name); + DEBUG(D_receive|D_acl) debug_printf_indent(">>Headers removed by %s ACL:\n", acl_name); for (h = header_list; h != NULL; h = h->next) if (h->type != htype_old) { @@ -1129,15 +1129,15 @@ if (acl_removed_headers != NULL) if (header_testname(h, s, Ustrlen(s), FALSE)) { h->type = htype_old; - DEBUG(D_receive|D_acl) debug_printf(" %s", h->text); + DEBUG(D_receive|D_acl) debug_printf_indent(" %s", h->text); } } acl_removed_headers = NULL; - DEBUG(D_receive|D_acl) debug_printf(">>\n"); + DEBUG(D_receive|D_acl) debug_printf_indent(">>\n"); } if (acl_added_headers == NULL) return; -DEBUG(D_receive|D_acl) debug_printf(">>Headers added by %s ACL:\n", acl_name); +DEBUG(D_receive|D_acl) debug_printf_indent(">>Headers added by %s ACL:\n", acl_name); for (h = acl_added_headers; h != NULL; h = next) { @@ -1148,7 +1148,7 @@ for (h = acl_added_headers; h != NULL; h = next) case htype_add_top: h->next = header_list; header_list = h; - DEBUG(D_receive|D_acl) debug_printf(" (at top)"); + DEBUG(D_receive|D_acl) debug_printf_indent(" (at top)"); break; case htype_add_rec: @@ -1163,7 +1163,7 @@ for (h = acl_added_headers; h != NULL; h = next) } h->next = last_received->next; last_received->next = h; - DEBUG(D_receive|D_acl) debug_printf(" (after Received:)"); + DEBUG(D_receive|D_acl) debug_printf_indent(" (after Received:)"); break; case htype_add_rfc: @@ -1178,7 +1178,7 @@ for (h = acl_added_headers; h != NULL; h = next) of all headers. Our current header must follow it. */ h->next = last_received->next; last_received->next = h; - DEBUG(D_receive|D_acl) debug_printf(" (before any non-Received: or Resent-*: header)"); + DEBUG(D_receive|D_acl) debug_printf_indent(" (before any non-Received: or Resent-*: header)"); break; default: @@ -1198,11 +1198,11 @@ for (h = acl_added_headers; h != NULL; h = next) h->type = header_checkname(h, FALSE); if (h->type >= 'a') h->type = htype_other; - DEBUG(D_receive|D_acl) debug_printf(" %s", header_last->text); + DEBUG(D_receive|D_acl) debug_printf_indent(" %s", header_last->text); } acl_added_headers = NULL; -DEBUG(D_receive|D_acl) debug_printf(">>\n"); +DEBUG(D_receive|D_acl) debug_printf_indent(">>\n"); } @@ -1354,7 +1354,7 @@ if (rc == OK) { (void) string_format(rfc822_file_path, sizeof(rfc822_file_path), "%s/scan/%s/%s", spool_directory, message_id, entry->d_name); - debug_printf("RFC822 attachment detected: running MIME ACL for '%s'\n", + DEBUG(D_receive) debug_printf("RFC822 attachment detected: running MIME ACL for '%s'\n", rfc822_file_path); break; } diff --git a/src/src/smtp_out.c b/src/src/smtp_out.c index 0b5e796d9..ba6153ea9 100644 --- a/src/src/smtp_out.c +++ b/src/src/smtp_out.c @@ -166,7 +166,7 @@ if ((sock = ip_socket(SOCK_STREAM, host_af)) < 0) return -1; if (setsockopt(sock, IPPROTO_TCP, TCP_NODELAY, US &on, sizeof(on))) HDEBUG(D_transport|D_acl|D_v) - debug_printf("failed to set NODELAY: %s ", strerror(errno)); + debug_printf_indent("failed to set NODELAY: %s ", strerror(errno)); /* Set DSCP value, if we can. For now, if we fail to set the value, we don't bomb out, just log it and continue in default traffic class. */ @@ -174,10 +174,10 @@ bomb out, just log it and continue in default traffic class. */ if (dscp && dscp_lookup(dscp, host_af, &dscp_level, &dscp_option, &dscp_value)) { HDEBUG(D_transport|D_acl|D_v) - debug_printf("DSCP \"%s\"=%x ", dscp, dscp_value); + debug_printf_indent("DSCP \"%s\"=%x ", dscp, dscp_value); if (setsockopt(sock, dscp_level, dscp_option, &dscp_value, sizeof(dscp_value)) < 0) HDEBUG(D_transport|D_acl|D_v) - debug_printf("failed to set DSCP: %s ", strerror(errno)); + debug_printf_indent("failed to set DSCP: %s ", strerror(errno)); /* If the kernel supports IPv4 and IPv6 on an IPv6 socket, we need to set the option for both; ignore failures here */ if (host_af == AF_INET6 && @@ -196,7 +196,7 @@ if (interface && ip_bind(sock, host_af, interface, 0) < 0) { save_errno = errno; HDEBUG(D_transport|D_acl|D_v) - debug_printf("unable to bind outgoing SMTP call to %s: %s", interface, + debug_printf_indent("unable to bind outgoing SMTP call to %s: %s", interface, strerror(errno)); } @@ -212,7 +212,7 @@ if (save_errno != 0) { HDEBUG(D_transport|D_acl|D_v) { - debug_printf("failed: %s", CUstrerror(save_errno)); + debug_printf_indent("failed: %s", CUstrerror(save_errno)); if (save_errno == ETIMEDOUT) debug_printf(" (timeout=%s)", readconf_printtime(timeout)); debug_printf("\n"); @@ -228,7 +228,7 @@ else { union sockaddr_46 interface_sock; EXIM_SOCKLEN_T size = sizeof(interface_sock); - HDEBUG(D_transport|D_acl|D_v) debug_printf("connected\n"); + HDEBUG(D_transport|D_acl|D_v) debug_printf_indent("connected\n"); if (getsockname(sock, (struct sockaddr *)(&interface_sock), &size) == 0) sending_ip_address = host_ntoa(-1, &interface_sock, NULL, &sending_port); else @@ -280,7 +280,7 @@ smtp_transport_options_block * ob = if (host->port != PORT_NONE) { HDEBUG(D_transport|D_acl|D_v) - debug_printf("Transport port=%d replaced by host-specific port=%d\n", port, + debug_printf_indent("Transport port=%d replaced by host-specific port=%d\n", port, host->port); port = host->port; } @@ -295,7 +295,7 @@ HDEBUG(D_transport|D_acl|D_v) #ifdef SUPPORT_SOCKS if (ob->socks_proxy) s = string_sprintf("%svia proxy ", s); #endif - debug_printf("Connecting to %s %s%s... ", host->name, callout_address, s); + debug_printf_indent("Connecting to %s %s%s... ", host->name, callout_address, s); } /* Create and connect the socket */ @@ -329,7 +329,7 @@ flush_buffer(smtp_outblock *outblock) int rc; int n = outblock->ptr - outblock->buffer; -HDEBUG(D_transport|D_acl) debug_printf("cmd buf flush %d bytes\n", n); +HDEBUG(D_transport|D_acl) debug_printf_indent("cmd buf flush %d bytes\n", n); #ifdef SUPPORT_TLS if (tls_out.active == outblock->sock) rc = tls_write(FALSE, outblock->buffer, n); @@ -339,7 +339,7 @@ else if (rc <= 0) { - HDEBUG(D_transport|D_acl) debug_printf("send failed: %s\n", strerror(errno)); + HDEBUG(D_transport|D_acl) debug_printf_indent("send failed: %s\n", strerror(errno)); return FALSE; } @@ -420,7 +420,7 @@ if (format) while (*p != 0) *p++ = '*'; } - HDEBUG(D_transport|D_acl|D_v) debug_printf(" SMTP>> %s\n", big_buffer); + HDEBUG(D_transport|D_acl|D_v) debug_printf_indent(" SMTP>> %s\n", big_buffer); } if (!noflush) @@ -501,7 +501,7 @@ for (;;) if((rc = ip_recv(sock, inblock->buffer, inblock->buffersize, timeout)) <= 0) { if (!errno) - DEBUG(D_deliver|D_transport|D_acl) debug_printf(" SMTP(closed)<<\n"); + DEBUG(D_deliver|D_transport|D_acl) debug_printf_indent(" SMTP(closed)<<\n"); break; } @@ -510,7 +510,7 @@ for (;;) ptrend = inblock->ptrend = inblock->buffer + rc; ptr = inblock->buffer; - DEBUG(D_transport|D_acl) debug_printf("read response data: size=%d\n", rc); + DEBUG(D_transport|D_acl) debug_printf_indent("read response data: size=%d\n", rc); } /* Get here if there has been some kind of recv() error; errno is set, but we @@ -563,7 +563,7 @@ for (;;) return FALSE; HDEBUG(D_transport|D_acl|D_v) - debug_printf(" %s %s\n", (ptr == buffer)? "SMTP<<" : " ", ptr); + debug_printf_indent(" %s %s\n", (ptr == buffer)? "SMTP<<" : " ", ptr); /* Check the format of the response: it must start with three digits; if these are followed by a space or end of line, the response is complete. If diff --git a/src/src/spam.c b/src/src/spam.c index ac25a881f..d4b95b2f9 100644 --- a/src/src/spam.c +++ b/src/src/spam.c @@ -251,7 +251,7 @@ if (*spamd_address == '$') else spamd_address_work = spamd_address; -DEBUG(D_acl) debug_printf("spamd: addrlist '%s'\n", spamd_address_work); +DEBUG(D_acl) debug_printf_indent("spamd: addrlist '%s'\n", spamd_address_work); /* check if previous spamd_address was expanded and has changed. dump cached results if so */ if ( spam_ok @@ -295,7 +295,7 @@ start = time(NULL); unsigned args; uschar * s; - DEBUG(D_acl) debug_printf("spamd: addr entry '%s'\n", address); + DEBUG(D_acl) debug_printf_indent("spamd: addr entry '%s'\n", address); sd = (spamd_address_container *)store_get(sizeof(spamd_address_container)); for (sublist = address, args = 0, spamd_param_init(sd); @@ -303,7 +303,7 @@ start = time(NULL); args++ ) { - DEBUG(D_acl) debug_printf("spamd: addr parm '%s'\n", s); + DEBUG(D_acl) debug_printf_indent("spamd: addr parm '%s'\n", s); switch (args) { case 0: sd->hostspec = s; @@ -342,7 +342,7 @@ start = time(NULL); { uschar * errstr; - DEBUG(D_acl) debug_printf("spamd: trying server %s\n", sd->hostspec); + DEBUG(D_acl) debug_printf_indent("spamd: trying server %s\n", sd->hostspec); for (;;) { @@ -350,7 +350,7 @@ start = time(NULL); || sd->retry <= 0 ) break; - DEBUG(D_acl) debug_printf("spamd: server %s: retry conn\n", sd->hostspec); + DEBUG(D_acl) debug_printf_indent("spamd: server %s: retry conn\n", sd->hostspec); while (sd->retry > 0) sd->retry = sleep(sd->retry); } if (spamd_sock >= 0) diff --git a/src/src/transports/smtp.c b/src/src/transports/smtp.c index aa15fd8d8..c1f5ad45a 100644 --- a/src/src/transports/smtp.c +++ b/src/src/transports/smtp.c @@ -2166,7 +2166,7 @@ writing RSET might have failed, or there may be other addresses whose hosts are specified in the transports, and therefore not visible at top level, in which case continue_more won't get set. */ -HDEBUG(D_transport|D_acl|D_v) debug_printf(" SMTP(close)>>\n"); +HDEBUG(D_transport|D_acl|D_v) debug_printf_indent(" SMTP(close)>>\n"); if (sx->send_quit) { shutdown(sx->outblock.sock, SHUT_WR); @@ -3287,7 +3287,7 @@ writing RSET might have failed, or there may be other addresses whose hosts are specified in the transports, and therefore not visible at top level, in which case continue_more won't get set. */ -HDEBUG(D_transport|D_acl|D_v) debug_printf(" SMTP(close)>>\n"); +HDEBUG(D_transport|D_acl|D_v) debug_printf_indent(" SMTP(close)>>\n"); if (sx.send_quit) { shutdown(sx.outblock.sock, SHUT_WR); diff --git a/src/src/transports/smtp_socks.c b/src/src/transports/smtp_socks.c index 33b25d1da..555843068 100644 --- a/src/src/transports/smtp_socks.c +++ b/src/src/transports/smtp_socks.c @@ -112,7 +112,7 @@ switch(method) case AUTH_NONE: return OK; case AUTH_NAME: - HDEBUG(D_transport|D_acl|D_v) debug_printf(" socks auth NAME '%s' '%s'\n", + HDEBUG(D_transport|D_acl|D_v) debug_printf_indent(" socks auth NAME '%s' '%s'\n", sob->auth_name, sob->auth_pwd); i = Ustrlen(sob->auth_name); j = Ustrlen(sob->auth_pwd); @@ -122,7 +122,7 @@ switch(method) HDEBUG(D_transport|D_acl|D_v) { int i; - debug_printf(" SOCKS>>"); + debug_printf_indent(" SOCKS>>"); for (i = 0; i<len; i++) debug_printf(" %02x", s[i]); debug_printf("\n"); } @@ -132,10 +132,10 @@ switch(method) ) return FAIL; HDEBUG(D_transport|D_acl|D_v) - debug_printf(" SOCKS<< %02x %02x\n", s[0], s[1]); + debug_printf_indent(" SOCKS<< %02x %02x\n", s[0], s[1]); if (s[0] == AUTH_NAME_VER && s[1] == 0) { - HDEBUG(D_transport|D_acl|D_v) debug_printf(" socks auth OK\n"); + HDEBUG(D_transport|D_acl|D_v) debug_printf_indent(" socks auth OK\n"); return OK; } @@ -278,7 +278,7 @@ for(;;) if ((idx = socks_get_proxy(proxies, nproxies)) < 0) { - HDEBUG(D_transport|D_acl|D_v) debug_printf(" no proxies left\n"); + HDEBUG(D_transport|D_acl|D_v) debug_printf_indent(" no proxies left\n"); errno = EBUSY; return -1; } @@ -304,7 +304,7 @@ for(;;) /* Send method-selection */ state = US"method select"; -HDEBUG(D_transport|D_acl|D_v) debug_printf(" SOCKS>> 05 01 %02x\n", sob->auth_type); +HDEBUG(D_transport|D_acl|D_v) debug_printf_indent(" SOCKS>> 05 01 %02x\n", sob->auth_type); buf[0] = 5; buf[1] = 1; buf[2] = sob->auth_type; if (send(fd, buf, 3, 0) < 0) goto snd_err; @@ -316,7 +316,7 @@ if ( !fd_ready(fd, tmo-time(NULL)) ) goto rcv_err; HDEBUG(D_transport|D_acl|D_v) - debug_printf(" SOCKS<< %02x %02x\n", buf[0], buf[1]); + debug_printf_indent(" SOCKS<< %02x %02x\n", buf[0], buf[1]); if ( buf[0] != 5 || socks_auth(fd, buf[1], sob, tmo) != OK ) @@ -351,7 +351,7 @@ state = US"connect"; HDEBUG(D_transport|D_acl|D_v) { int i; - debug_printf(" SOCKS>>"); + debug_printf_indent(" SOCKS>>"); for (i = 0; i<size; i++) debug_printf(" %02x", buf[i]); debug_printf("\n"); } @@ -368,7 +368,7 @@ if ( !fd_ready(fd, tmo-time(NULL)) HDEBUG(D_transport|D_acl|D_v) { int i; - debug_printf(" SOCKS>>"); + debug_printf_indent(" SOCKS>>"); for (i = 0; i<size; i++) debug_printf(" %02x", buf[i]); debug_printf("\n"); } @@ -383,12 +383,12 @@ proxy_external_port = ntohs(*((uint16_t *)(buf + (buf[3] == 4 ? 20 : 8)))); proxy_session = TRUE; HDEBUG(D_transport|D_acl|D_v) - debug_printf(" proxy farside: [%s]:%d\n", proxy_external_address, proxy_external_port); + debug_printf_indent(" proxy farside: [%s]:%d\n", proxy_external_address, proxy_external_port); return fd; snd_err: - HDEBUG(D_transport|D_acl|D_v) debug_printf(" proxy snd_err %s: %s\n", state, strerror(errno)); + HDEBUG(D_transport|D_acl|D_v) debug_printf_indent(" proxy snd_err %s: %s\n", state, strerror(errno)); return -1; proxy_err: @@ -396,12 +396,12 @@ proxy_err: struct socks_err * se = buf[1] > nelem(socks_errs) ? NULL : socks_errs + buf[1]; HDEBUG(D_transport|D_acl|D_v) - debug_printf(" proxy %s: %s\n", state, se ? se->reason : US"unknown error code received"); + debug_printf_indent(" proxy %s: %s\n", state, se ? se->reason : US"unknown error code received"); errno = se ? se->errcode : EPROTO; } rcv_err: - HDEBUG(D_transport|D_acl|D_v) debug_printf(" proxy rcv_err %s: %s\n", state, strerror(errno)); + HDEBUG(D_transport|D_acl|D_v) debug_printf_indent(" proxy rcv_err %s: %s\n", state, strerror(errno)); if (!errno) errno = EPROTO; else if (errno == ENOENT) errno = ECONNABORTED; return -1; diff --git a/src/src/verify.c b/src/src/verify.c index 7b136d4cc..9c4776b31 100644 --- a/src/src/verify.c +++ b/src/src/verify.c @@ -804,12 +804,12 @@ tls_retry_connection: break; HDEBUG(D_acl|D_v) - debug_printf("problem after random/rset/mfrom; reopen conn\n"); + debug_printf_indent("problem after random/rset/mfrom; reopen conn\n"); random_local_part = NULL; #ifdef SUPPORT_TLS tls_close(FALSE, TRUE); #endif - HDEBUG(D_transport|D_acl|D_v) debug_printf(" SMTP(close)>>\n"); + HDEBUG(D_transport|D_acl|D_v) debug_printf_indent(" SMTP(close)>>\n"); (void)close(sx.inblock.sock); sx.inblock.sock = sx.outblock.sock = -1; #ifndef DISABLE_EVENT @@ -889,7 +889,7 @@ tls_retry_connection: for cutthrough. But no way to handle a subsequent rcpt, so just refuse any */ cancel_cutthrough_connection("postmaster verify"); - HDEBUG(D_acl|D_v) debug_printf("Cutthrough cancelled by presence of postmaster verify\n"); + HDEBUG(D_acl|D_v) debug_printf_indent("Cutthrough cancelled by presence of postmaster verify\n"); done = smtp_write_command(&sx.outblock, FALSE, "RSET\r\n") >= 0 && smtp_read_response(&sx.inblock, sx.buffer, @@ -1017,7 +1017,7 @@ no_conn: && !sx.lmtp ) { - HDEBUG(D_acl|D_v) debug_printf("holding verify callout open for cutthrough delivery\n"); + HDEBUG(D_acl|D_v) debug_printf_indent("holding verify callout open for cutthrough delivery\n"); cutthrough.fd = sx.outblock.sock; /* We assume no buffer in use in the outblock */ cutthrough.nrcpt = 1; @@ -1054,7 +1054,7 @@ no_conn: #ifdef SUPPORT_TLS tls_close(FALSE, TRUE); #endif - HDEBUG(D_transport|D_acl|D_v) debug_printf(" SMTP(close)>>\n"); + HDEBUG(D_transport|D_acl|D_v) debug_printf_indent(" SMTP(close)>>\n"); (void)close(sx.inblock.sock); sx.inblock.sock = sx.outblock.sock = -1; #ifndef DISABLE_EVENT @@ -1131,7 +1131,7 @@ int rc; get rewritten. */ addr2 = *addr; -HDEBUG(D_acl) debug_printf("----------- %s cutthrough setup ------------\n", +HDEBUG(D_acl) debug_printf_indent("----------- %s cutthrough setup ------------\n", rcpt_count > 1 ? "more" : "start"); rc = verify_address(&addr2, NULL, vopt_is_recipient | vopt_callout_recipsender | vopt_callout_no_cache, @@ -1139,7 +1139,7 @@ rc = verify_address(&addr2, NULL, NULL, NULL, NULL); addr->message = addr2.message; addr->user_message = addr2.user_message; -HDEBUG(D_acl) debug_printf("----------- end cutthrough setup ------------\n"); +HDEBUG(D_acl) debug_printf_indent("----------- end cutthrough setup ------------\n"); return rc; } @@ -1164,7 +1164,7 @@ if( return TRUE; } -HDEBUG(D_transport|D_acl) debug_printf("cutthrough_send failed: %s\n", strerror(errno)); +HDEBUG(D_transport|D_acl) debug_printf_indent("cutthrough_send failed: %s\n", strerror(errno)); return FALSE; } @@ -1262,7 +1262,7 @@ cutthrough_predata(void) if(cutthrough.fd < 0) return FALSE; -HDEBUG(D_transport|D_acl|D_v) debug_printf(" SMTP>> DATA\n"); +HDEBUG(D_transport|D_acl|D_v) debug_printf_indent(" SMTP>> DATA\n"); cutthrough_puts(US"DATA\r\n", 6); cutthrough_flush_send(); @@ -1300,7 +1300,7 @@ if(cutthrough.fd < 0) /* We share a routine with the mainline transport to handle header add/remove/rewrites, but having a separate buffered-output function (for now) */ -HDEBUG(D_acl) debug_printf("----------- start cutthrough headers send -----------\n"); +HDEBUG(D_acl) debug_printf_indent("----------- start cutthrough headers send -----------\n"); tctx.tblock = cutthrough.addr.transport; tctx.addr = &cutthrough.addr; @@ -1311,7 +1311,7 @@ tctx.options = topt_use_crlf; if (!transport_headers_send(cutthrough.fd, &tctx, &cutthrough_write_chunk)) return FALSE; -HDEBUG(D_acl) debug_printf("----------- done cutthrough headers send ------------\n"); +HDEBUG(D_acl) debug_printf_indent("----------- done cutthrough headers send ------------\n"); return TRUE; } @@ -1326,7 +1326,7 @@ if(cutthrough.fd >= 0) conn before the final dot. */ ctblock.ptr = ctbuffer; - HDEBUG(D_transport|D_acl|D_v) debug_printf(" SMTP>> QUIT\n"); + HDEBUG(D_transport|D_acl|D_v) debug_printf_indent(" SMTP>> QUIT\n"); _cutthrough_puts(US"QUIT\r\n", 6); /* avoid recursion */ _cutthrough_flush_send(); @@ -1336,10 +1336,10 @@ if(cutthrough.fd >= 0) #ifdef SUPPORT_TLS tls_close(FALSE, TRUE); #endif - HDEBUG(D_transport|D_acl|D_v) debug_printf(" SMTP(close)>>\n"); + HDEBUG(D_transport|D_acl|D_v) debug_printf_indent(" SMTP(close)>>\n"); (void)close(cutthrough.fd); cutthrough.fd = -1; - HDEBUG(D_acl) debug_printf("----------- cutthrough shutdown (%s) ------------\n", why); + HDEBUG(D_acl) debug_printf_indent("----------- cutthrough shutdown (%s) ------------\n", why); } ctblock.ptr = ctbuffer; } @@ -1364,7 +1364,7 @@ cutthrough_finaldot(void) { uschar res; address_item * addr; -HDEBUG(D_transport|D_acl|D_v) debug_printf(" SMTP>> .\n"); +HDEBUG(D_transport|D_acl|D_v) debug_printf_indent(" SMTP>> .\n"); /* Assume data finshed with new-line */ if( !cutthrough_puts(US".", 1) |