Hello, I am building a Postfix 2.8.5 server. And I am delivering my mail only to the Dovecot IMAP mail store using LMTP.
I am following the Wiki pages at www.postfix.org/VIRTUAL_README.html and http://www.postfix.org/lmtp.8.html for guidance in these things. In the testing of LMTP delivery I am having a challenge. I receive in Postfix logs for 'lmtp -v' a few "Temporary internal error" messages. I see the several messages, but I do not know the next step in understanding and fixing it. Can you help me to learn what next to do or how to see more details that are useful? For your interest in helping I am including that log information in this message. TJ sendmail -i -t <<EOF From: root To: t...@tjserver.loc Subject: testing testing EOF Log -> Oct 4 08:26:17 tjserver postfix/pickup[7145]: 086E9204BE: uid=0 from=<root> Oct 4 08:26:17 tjserver postfix/cleanup[7148]: 086E9204BE: message-id=<20111004152617.086e920...@tjserver.loc> Oct 4 08:26:17 tjserver postfix/qmgr[7143]: 086E9204BE: from=<r...@tjserver.loc>, size=387, nrcpt=1 (queue active) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: name_mask: ipv4 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: inet_addr_local: configured 4 IPv4 addresses Oct 4 08:26:17 tjserver postfix/lmtp[7150]: process generation: 54 (54) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: match_string: fast_flush_domains ~? debug_peer_list Oct 4 08:26:17 tjserver postfix/lmtp[7150]: match_string: fast_flush_domains ~? smtpd_access_maps Oct 4 08:26:17 tjserver postfix/lmtp[7150]: match_list_match: fast_flush_domains: no match Oct 4 08:26:17 tjserver postfix/lmtp[7150]: name_mask: canonical Oct 4 08:26:17 tjserver postfix/lmtp[7150]: name_mask: virtual Oct 4 08:26:17 tjserver postfix/lmtp[7150]: name_mask: dns Oct 4 08:26:17 tjserver postfix/lmtp[7150]: host name lookup methods: dns Oct 4 08:26:17 tjserver postfix/lmtp[7150]: auto_clnt_create: transport=local endpoint=private/scache Oct 4 08:26:17 tjserver postfix/lmtp[7150]: connection established Oct 4 08:26:17 tjserver postfix/lmtp[7150]: master_notify: status 0 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: deliver_request_initial: send initial status Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr status = 0 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: flags Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: flags Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: 3 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: queue_name Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: queue_name Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: active Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: queue_id Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: queue_id Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: 086E9204BE Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: offset Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: offset Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: 190 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: size Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: size Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: 387 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: nexthop Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: nexthop Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: unix:private/dovecot-lmtp Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: encoding Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: encoding Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: (end) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: sender Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: sender Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: r...@tjserver.loc Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: envelope_id Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: envelope_id Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: (end) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: ret_flags Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: ret_flags Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: 0 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: time Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: time Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: mCWLTgAAAADExg4AAAAAAJkli04AAAAAgh8BAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA== Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: log_client_name Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: log_client_name Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: (end) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: log_client_address Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: log_client_address Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: (end) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: log_client_port Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: log_client_port Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: (end) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: log_protocol_name Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: log_protocol_name Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: (end) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: log_helo_name Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: log_helo_name Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: (end) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: sasl_method Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: sasl_method Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: (end) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: sasl_username Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: sasl_username Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: (end) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: sasl_sender Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: sasl_sender Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: (end) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: log_ident Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: log_ident Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: (end) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: rewrite_context Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: rewrite_context Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: local Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: recipient_count Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: recipient_count Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: 1 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: (list terminator) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: (end) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: original_recipient Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: original_recipient Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: tju...@tjserver.loc Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: recipient Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: recipient Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: tju...@tjserver.loc Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: offset Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: offset Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: 617 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: dsn_orig_rcpt Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: dsn_orig_rcpt Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: (end) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: notify_flags Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: notify_flags Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: 0 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: lmtp socket: wanted attribute: (list terminator) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: (end) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: deliver_request_get: file active/086E9204BE Oct 4 08:26:17 tjserver postfix/lmtp[7150]: deliver_message: from r...@tjserver.loc Oct 4 08:26:17 tjserver postfix/lmtp[7150]: smtp_connect_unix: trying: private/dovecot-lmtp... Oct 4 08:26:17 tjserver postfix/lmtp[7150]: global TLS level: none Oct 4 08:26:17 tjserver postfix/lmtp[7150]: < tjserver.loc[private/dovecot-lmtp]: 220 tjserver.loc Dovecot LMTP ready Oct 4 08:26:17 tjserver postfix/lmtp[7150]: > tjserver.loc[private/dovecot-lmtp]: LHLO tjserver.loc Oct 4 08:26:17 tjserver postfix/lmtp[7150]: < tjserver.loc[private/dovecot-lmtp]: 250-tjserver.loc Oct 4 08:26:17 tjserver postfix/lmtp[7150]: < tjserver.loc[private/dovecot-lmtp]: 250-8BITMIME Oct 4 08:26:17 tjserver postfix/lmtp[7150]: < tjserver.loc[private/dovecot-lmtp]: 250-ENHANCEDSTATUSCODES Oct 4 08:26:17 tjserver postfix/lmtp[7150]: < tjserver.loc[private/dovecot-lmtp]: 250 PIPELINING Oct 4 08:26:17 tjserver postfix/lmtp[7150]: server features: 0x7 size 0 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: Using LMTP PIPELINING, TCP send buffer size is 256960, PIPELINING buffer size is 4096 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: > tjserver.loc[private/dovecot-lmtp]: MAIL FROM:<r...@tjserver.loc> Oct 4 08:26:17 tjserver postfix/lmtp[7150]: > tjserver.loc[private/dovecot-lmtp]: RCPT TO:<tju...@tjserver.loc> Oct 4 08:26:17 tjserver postfix/lmtp[7150]: > tjserver.loc[private/dovecot-lmtp]: DATA Oct 4 08:26:17 tjserver postfix/lmtp[7150]: < tjserver.loc[private/dovecot-lmtp]: 250 2.1.0 OK Oct 4 08:26:17 tjserver postfix/lmtp[7150]: < tjserver.loc[private/dovecot-lmtp]: 250 2.1.5 OK Oct 4 08:26:17 tjserver postfix/lmtp[7150]: < tjserver.loc[private/dovecot-lmtp]: 354 OK Oct 4 08:26:17 tjserver postfix/lmtp[7150]: > tjserver.loc[private/dovecot-lmtp]: . Oct 4 08:26:17 tjserver postfix/lmtp[7150]: > tjserver.loc[private/dovecot-lmtp]: QUIT Oct 4 08:26:17 tjserver postfix/lmtp[7150]: < tjserver.loc[private/dovecot-lmtp]: 451 4.3.0 <tju...@tjserver.loc> Temporary internal error Oct 4 08:26:17 tjserver postfix/lmtp[7150]: connect to subsystem private/defer Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr nrequest = 0 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr flags = 0 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr queue_id = 086E9204BE Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr original_recipient = tju...@tjserver.loc Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr recipient = tju...@tjserver.loc Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr offset = 617 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr dsn_orig_rcpt = Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr notify_flags = 0 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr status = 4.3.0 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr diag_type = smtp Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr diag_text = 451 4.3.0 <tju...@tjserver.loc> Temporary internal error Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr mta_type = dns Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr mta_mname = tjserver.loc Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr action = delayed Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr reason = host tjserver.loc[private/dovecot-lmtp] said: 451 4.3.0 <tju...@tjserver.loc> Temporary internal error (in reply to end of DATA command) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: private/defer socket: wanted attribute: status Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: status Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute value: 0 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: private/defer socket: wanted attribute: (list terminator) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: input attribute name: (end) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: 086E9204BE: to=<tju...@tjserver.loc>, relay=tjserver.loc[private/dovecot-lmtp], delay=0.13, delays=0.11/0.02/0/0, dsn=4.3.0, status=deferred (host tjserver.loc[private/dovecot-lmtp] said: 451 4.3.0 <tju...@tjserver.loc> Temporary internal error (in reply to end of DATA command)) Oct 4 08:26:17 tjserver postfix/lmtp[7150]: flush_add: site tjserver.loc id 086E9204BE Oct 4 08:26:17 tjserver postfix/lmtp[7150]: match_hostname: tjserver.loc ~? localhost.tjserver.loc Oct 4 08:26:17 tjserver postfix/lmtp[7150]: match_hostname: tjserver.loc ~? localhost Oct 4 08:26:17 tjserver postfix/lmtp[7150]: match_list_match: tjserver.loc: no match Oct 4 08:26:17 tjserver postfix/lmtp[7150]: flush_add: site tjserver.loc id 086E9204BE status 4 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: smtp_loop: got 1 of 1 end-of-data replies Oct 4 08:26:17 tjserver postfix/lmtp[7150]: < tjserver.loc[private/dovecot-lmtp]: 221 2.0.0 Client quit Oct 4 08:26:17 tjserver postfix/lmtp[7150]: name_mask: resource Oct 4 08:26:17 tjserver postfix/lmtp[7150]: name_mask: software Oct 4 08:26:17 tjserver postfix/lmtp[7150]: deliver_request_final: send: "" -1 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr status = Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr diag_type = Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr diag_text = Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr mta_type = Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr mta_mname = Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr action = Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr reason = Oct 4 08:26:17 tjserver postfix/lmtp[7150]: send attr status = 4294967295 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: master_notify: status 1 Oct 4 08:26:17 tjserver postfix/lmtp[7150]: connection closed
