Viktor Dukhovni: > > but, some other transports (not pipe) do have downstream information, so > > wouldn't it be better to have a similar output? > > There is no expectation that the first line of output is particularly > meaningful. This is not a well-defined interface, and scripts > might unexpectedly output some text before the intended audit output > (necessarily late in the script since you're reporting downstream > queue-ids for correlation, ...)
True, however there is precedent where the pipe(8) daemon parses command output. When command output starts with a well-formed enhanced status code, then this may override a non-zero program exit status code, and text after the enhanced status code is logged and returned in delivery status notifications. For example the following script unconditionally defers delivery, regardless of the non-zero exit status used: #!/bin/sh cat >/dev/null echo 4.0.0 We are doomed! exit 1 (4.x.x means defer, anything else means bounce). In that light, capturing some text from successful command execution introduces no new problems. With the following patch, the pipe(8) daemon logs some command output after successful delivery as: dsn=2.0.0, status=sent (delivered via XXX service (YYY))" where XXX is the master.cf service name and YYY is command output. The code is somewhat clumsy because it overwrites text with itself. Wietse 20140605 Feature: the pipe(8) daemon logs some command output after successful delivery as "dsn=2.0.0, status=sent (delivered via XXX service (YYY))" where XXX is the master.cf service name, and YYY is command output. Files: pipe/command.c, pipe.c. diff --exclude=man --exclude=html --exclude=README_FILES --exclude=.indent.pro --exclude=Makefile.in --exclude=INSTALL -cr /var/tmp/postfix-2.12-20140531/src/global/pipe_command.c ./src/global/pipe_command.c *** /var/tmp/postfix-2.12-20140531/src/global/pipe_command.c Mon Dec 6 09:56:06 2010 --- ./src/global/pipe_command.c Thu Jun 5 14:27:06 2014 *************** *** 675,680 **** --- 676,682 ---- vstring_sprintf_append(why->reason, ": \"%s\"", args.command); return (PIPE_STAT_BOUNCE); } else { + vstring_strcpy(why->reason, log_buf); return (PIPE_STAT_OK); } } diff --exclude=man --exclude=html --exclude=README_FILES --exclude=.indent.pro --exclude=Makefile.in --exclude=INSTALL -cr /var/tmp/postfix-2.12-20140531/src/pipe/pipe.c ./src/pipe/pipe.c *** /var/tmp/postfix-2.12-20140531/src/pipe/pipe.c Thu May 15 11:19:26 2014 --- ./src/pipe/pipe.c Thu Jun 5 15:01:48 2014 *************** *** 1008,1013 **** --- 1008,1016 ---- int status; int result = 0; int n; + char *saved_text; + char *reason; + size_t len_reason; /* * Depending on the result, bounce or defer the message, and mark the *************** *** 1015,1023 **** */ switch (command_status) { case PIPE_STAT_OK: dsb_update(why, "2.0.0", (attr->flags & PIPE_OPT_FINAL_DELIVERY) ? "delivered" : "relayed", DSB_SKIP_RMTA, DSB_SKIP_REPLY, ! "delivered via %s service", service); (void) DSN_FROM_DSN_BUF(why); for (n = 0; n < request->rcpt_list.len; n++) { rcpt = request->rcpt_list.info + n; --- 1018,1037 ---- */ switch (command_status) { case PIPE_STAT_OK: + reason = STR(why->reason); + len_reason = trimblanks(reason, VSTRING_LEN(why->reason)) - reason; + if (len_reason > 100) + len_reason = 100; + if (len_reason > 0) + saved_text = + vstring_export(vstring_sprintf(vstring_alloc(len_reason), + " (%.*s)", (int) len_reason, reason)); + else + saved_text = mystrdup(""); /* uses shared R/O storage */ dsb_update(why, "2.0.0", (attr->flags & PIPE_OPT_FINAL_DELIVERY) ? "delivered" : "relayed", DSB_SKIP_RMTA, DSB_SKIP_REPLY, ! "delivered via %s service%s", service, saved_text); ! myfree(saved_text); (void) DSN_FROM_DSN_BUF(why); for (n = 0; n < request->rcpt_list.len; n++) { rcpt = request->rcpt_list.info + n; diff --exclude=man --exclude=html --exclude=README_FILES --exclude=.indent.pro --exclude=Makefile.in --exclude=INSTALL -cr /var/tmp/postfix-2.12-20140531/src/tls/tls_server.c ./src/tls/tls_server.c *** /var/tmp/postfix-2.12-20140531/src/tls/tls_server.c Sun Apr 6 19:00:17 2014 --- ./src/tls/tls_server.c Tue Jun 3 08:43:10 2014 *************** *** 164,169 **** --- 164,178 ---- */ static const char server_session_id_context[] = "Postfix/TLS"; + #if OPENSSL_VERSION_NUMBER >= 0x1000000fL + #define GET_SID(s, v, lptr) ((v) = SSL_SESSION_get_id((s), (lptr))) + + #else /* Older OpenSSL releases */ + #define GET_SID(s, v, lptr) \ + do { (v) = (s)->session_id; *(lptr) = (s)->session_id_length; } while (0) + + #endif /* OPENSSL_VERSION_NUMBER */ + /* get_server_session_cb - callback to retrieve session from server cache */ static SSL_SESSION *get_server_session_cb(SSL *ssl, unsigned char *session_id, *************** *** 221,234 **** { VSTRING *cache_id; SSL_SESSION *session = SSL_get_session(TLScontext->con); SSL_CTX_remove_session(ctx, session); if (TLScontext->cache_type == 0) return; ! GEN_CACHE_ID(cache_id, session->session_id, session->session_id_length, ! TLScontext->serverid); if (TLScontext->log_mask & TLS_LOG_CACHE) msg_info("%s: remove session %s from %s cache", TLScontext->namaddr, --- 230,245 ---- { VSTRING *cache_id; SSL_SESSION *session = SSL_get_session(TLScontext->con); + const unsigned char *sid; + unsigned int sid_length; SSL_CTX_remove_session(ctx, session); if (TLScontext->cache_type == 0) return; ! GET_SID(session, sid, &sid_length); ! GEN_CACHE_ID(cache_id, sid, sid_length, TLScontext->serverid); if (TLScontext->log_mask & TLS_LOG_CACHE) msg_info("%s: remove session %s from %s cache", TLScontext->namaddr, *************** *** 246,257 **** VSTRING *cache_id; TLS_SESS_STATE *TLScontext; VSTRING *session_data; if ((TLScontext = SSL_get_ex_data(ssl, TLScontext_index)) == 0) msg_panic("%s: null TLScontext in new session callback", myname); ! GEN_CACHE_ID(cache_id, session->session_id, session->session_id_length, ! TLScontext->serverid); if (TLScontext->log_mask & TLS_LOG_CACHE) msg_info("%s: save session %s to %s cache", TLScontext->namaddr, --- 257,270 ---- VSTRING *cache_id; TLS_SESS_STATE *TLScontext; VSTRING *session_data; + const unsigned char *sid; + unsigned int sid_length; if ((TLScontext = SSL_get_ex_data(ssl, TLScontext_index)) == 0) msg_panic("%s: null TLScontext in new session callback", myname); ! GET_SID(session, sid, &sid_length); ! GEN_CACHE_ID(cache_id, sid, sid_length, TLScontext->serverid); if (TLScontext->log_mask & TLS_LOG_CACHE) msg_info("%s: save session %s to %s cache", TLScontext->namaddr,