Reuben Farrelly
2017-Dec-23 06:18 UTC
dovecot-submission SMTP send error with Thunderbird (BODY=8BITMIME)
Hi, With latest 2.3 -git (and 2.3.0 release), I'm running into this error with Thunderbird: "An error occurred while sending mail. The mail server responded: 5.5.4 Unsupported mail BODY type. Please verify that your email address is correct in your account settings and try again." This is fatal and means Thunderbird cannot use the submission service - fortunately I can revert back to a native Postfix service which works. Here's a tcpdump of the conversation: thunderstorm /etc/dovecot/conf.d # tcpdump -A port 587 dropped privs to tcpdump tcpdump: verbose output suppressed, use -v or -vv for full protocol decode listening on eth0, link-type EN10MB (Ethernet), capture size 262144 bytes 14:12:19.975982 IP6 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175 > inside-mail.reub.net.submission: Flags [S], seq 572328223, win 64800, options [mss 1440,nop,wscale 8,nop,nop,sackOK], length 0 `._.. .? .D.1...E.....>. .D.1..........#...K". ........ .w.............. 14:12:19.976022 IP6 inside-mail.reub.net.submission > 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175: Flags [S.], seq 3954361671, ack 572328224, win 28800, options [mss 1440,nop,nop,sackOK,nop,wscale 7], length 0 `.c|. .@ .D.1..........# .D.1...E.....>..K.....G". ..p.:4.............. 14:12:19.976158 IP6 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175 > inside-mail.reub.net.submission: Flags [.], ack 1, win 8235, length 0 `._....? .D.1...E.....>. .D.1..........#...K". ...HP. +. .. 14:12:19.983409 IP6 inside-mail.reub.net.submission > 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175: Flags [P.], seq 1:43, ack 1, win 225, length 42 `.c|.>.@ .D.1..........# .D.1...E.....>..K.....H". P...:R..220 thunderstorm.reub.net Dovecot ready. 14:12:19.992790 IP6 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175 > inside-mail.reub.net.submission: Flags [P.], seq 1:54, ack 43, win 8234, length 53 `._..I.? .D.1...E.....>. .D.1..........#...K". ...rP. *.H..EHLO [IPv6:2001:44b8:31d4:1311:45ec:e191:8093:3e9d] 14:12:19.992828 IP6 inside-mail.reub.net.submission > 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175: Flags [.], ack 54, win 225, length 0 `.c|...@ .D.1..........# .D.1...E.....>..K.....r". UP...:(.. 14:12:19.993027 IP6 inside-mail.reub.net.submission > 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175: Flags [P.], seq 43:200, ack 54, win 225, length 157 `.c|...@ .D.1..........# .D.1...E.....>..K.....r". UP...:...250-thunderstorm.reub.net 250-8BITMIME 250-AUTH PLAIN LOGIN 250-BURL imap 250-CHUNKING 250-ENHANCEDSTATUSCODES 250-SIZE 250-STARTTLS 250 PIPELINING 14:12:20.015953 IP6 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175 > inside-mail.reub.net.submission: Flags [P.], seq 54:91, ack 200, win 8234, length 37 `._..9.? .D.1...E.....>. .D.1..........#...K". U....P. *....AUTH PLAIN xxxx 14:12:20.035676 IP6 inside-mail.reub.net.submission > 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175: Flags [P.], seq 200:222, ack 91, win 225, length 22 `.c|.*.@ .D.1..........# .D.1...E.....>..K......". zP...:>..235 2.7.0 Logged in. 14:12:20.036642 IP6 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175 > inside-mail.reub.net.submission: Flags [P.], seq 91:143, ack 222, win 8234, length 52 `._..H.? .D.1...E.....>. .D.1..........#...K". z...%P. *....MAIL FROM:<xxx at reub.net> BODY=8BITMIME SIZE=444 14:12:20.036826 IP6 inside-mail.reub.net.submission > 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175: Flags [P.], seq 222:260, ack 143, win 225, length 38 `.c|.:.@ .D.1..........# .D.1...E.....>..K.....%". .P...:N..555 5.5.4 Unsupported mail BODY type 14:12:20.089196 IP6 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175 > inside-mail.reub.net.submission: Flags [.], ack 260, win 8233, length 0 `._....? .D.1...E.....>. .D.1..........#...K". ....KP. ).... Curiously enabling rawlog doesn't capture this error, which is why I used tcpdump above. The logs from it like this: thunderstorm /run/dovecot/rawlogs # cat 20171219-141149.5633.1.in 1513653109.109030 220 thunderstorm.reub.net ESMTP Postfix (3.3-20171028) 1513653109.109266 250-thunderstorm.reub.net 1513653109.109266 250-PIPELINING 1513653109.109266 250-SIZE 40960000 1513653109.109266 250-VRFY 1513653109.109266 250-ETRN 1513653109.109266 250-STARTTLS 1513653109.109266 250-ENHANCEDSTATUSCODES 1513653109.109266 250-8BITMIME 1513653109.109266 250-DSN 1513653109.109266 250 SMTPUTF8 1513653130.973720 221 2.0.0 Bye thunderstorm /run/dovecot/rawlogs # cat 20171219-141149.5633.1.out 1513653109.109087 EHLO thunderstorm.reub.net 1513653130.973351 QUIT 1513653130.973829 QUIT thunderstorm /run/dovecot/rawlogs # This with: # Write protocol logs for relay connection to this directory for debugging #submission_relay_rawlog_dir submission_relay_rawlog_dir = /run/dovecot/rawlogs/ Is this a separate but unrelated problem with rawlog support in this the submission? I would have expected it to capture the full conversation log including any protocol errors and failures like this. Reuben
Aki Tuomi
2017-Dec-23 08:46 UTC
dovecot-submission SMTP send error with Thunderbird (BODY=8BITMIME)
Hi, thank you for your report. We'll look into it! Aki> On December 23, 2017 at 8:18 AM Reuben Farrelly <reuben-dovecot at reub.net> wrote: > > > Hi, > > With latest 2.3 -git (and 2.3.0 release), I'm running into this error > with Thunderbird: > > "An error occurred while sending mail. The mail server responded: 5.5.4 > Unsupported mail BODY type. Please verify that your email address is > correct in your account settings and try again." > > This is fatal and means Thunderbird cannot use the submission service - > fortunately I can revert back to a native Postfix service which works. > > Here's a tcpdump of the conversation: > > thunderstorm /etc/dovecot/conf.d # tcpdump -A port 587 > > dropped privs to tcpdump > tcpdump: verbose output suppressed, use -v or -vv for full protocol decode > listening on eth0, link-type EN10MB (Ethernet), capture size 262144 bytes > > > 14:12:19.975982 IP6 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175 > > inside-mail.reub.net.submission: Flags [S], seq 572328223, win 64800, > options [mss 1440,nop,wscale 8,nop,nop,sackOK], length 0 > `._.. .? .D.1...E.....>. .D.1..........#...K". ........ .w.............. > 14:12:19.976022 IP6 inside-mail.reub.net.submission > > 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175: Flags [S.], seq > 3954361671, ack 572328224, win 28800, options [mss > 1440,nop,nop,sackOK,nop,wscale 7], length 0 > `.c|. .@ .D.1..........# .D.1...E.....>..K.....G". ..p.:4.............. > 14:12:19.976158 IP6 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175 > > inside-mail.reub.net.submission: Flags [.], ack 1, win 8235, length 0 > `._....? .D.1...E.....>. .D.1..........#...K". ...HP. +. .. > 14:12:19.983409 IP6 inside-mail.reub.net.submission > > 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175: Flags [P.], seq 1:43, ack > 1, win 225, length 42 > `.c|.>.@ .D.1..........# .D.1...E.....>..K.....H". P...:R..220 > thunderstorm.reub.net Dovecot ready. > > 14:12:19.992790 IP6 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175 > > inside-mail.reub.net.submission: Flags [P.], seq 1:54, ack 43, win 8234, > length 53 > `._..I.? .D.1...E.....>. .D.1..........#...K". ...rP. *.H..EHLO > [IPv6:2001:44b8:31d4:1311:45ec:e191:8093:3e9d] > > 14:12:19.992828 IP6 inside-mail.reub.net.submission > > 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175: Flags [.], ack 54, win > 225, length 0 > `.c|...@ .D.1..........# .D.1...E.....>..K.....r". UP...:(.. > 14:12:19.993027 IP6 inside-mail.reub.net.submission > > 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175: Flags [P.], seq 43:200, > ack 54, win 225, length 157 > `.c|...@ .D.1..........# .D.1...E.....>..K.....r". > UP...:...250-thunderstorm.reub.net > 250-8BITMIME > 250-AUTH PLAIN LOGIN > 250-BURL imap > 250-CHUNKING > 250-ENHANCEDSTATUSCODES > 250-SIZE > 250-STARTTLS > 250 PIPELINING > > 14:12:20.015953 IP6 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175 > > inside-mail.reub.net.submission: Flags [P.], seq 54:91, ack 200, win > 8234, length 37 > `._..9.? .D.1...E.....>. .D.1..........#...K". U....P. *....AUTH PLAIN xxxx > > 14:12:20.035676 IP6 inside-mail.reub.net.submission > > 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175: Flags [P.], seq 200:222, > ack 91, win 225, length 22 > `.c|.*.@ .D.1..........# .D.1...E.....>..K......". zP...:>..235 > 2.7.0 Logged in. > > 14:12:20.036642 IP6 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175 > > inside-mail.reub.net.submission: Flags [P.], seq 91:143, ack 222, win > 8234, length 52 > `._..H.? .D.1...E.....>. .D.1..........#...K". z...%P. *....MAIL > FROM:<xxx at reub.net> BODY=8BITMIME SIZE=444 > > 14:12:20.036826 IP6 inside-mail.reub.net.submission > > 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175: Flags [P.], seq 222:260, > ack 143, win 225, length 38 > `.c|.:.@ .D.1..........# .D.1...E.....>..K.....%". .P...:N..555 > 5.5.4 Unsupported mail BODY type > > 14:12:20.089196 IP6 2001:44b8:31d4:1311:45ec:e191:8093:3e9d.61175 > > inside-mail.reub.net.submission: Flags [.], ack 260, win 8233, length 0 > `._....? .D.1...E.....>. .D.1..........#...K". ....KP. ).... > > > Curiously enabling rawlog doesn't capture this error, which is why I > used tcpdump above. The logs from it like this: > > thunderstorm /run/dovecot/rawlogs # cat 20171219-141149.5633.1.in > 1513653109.109030 220 thunderstorm.reub.net ESMTP Postfix (3.3-20171028) > 1513653109.109266 250-thunderstorm.reub.net > 1513653109.109266 250-PIPELINING > 1513653109.109266 250-SIZE 40960000 > 1513653109.109266 250-VRFY > 1513653109.109266 250-ETRN > 1513653109.109266 250-STARTTLS > 1513653109.109266 250-ENHANCEDSTATUSCODES > 1513653109.109266 250-8BITMIME > 1513653109.109266 250-DSN > 1513653109.109266 250 SMTPUTF8 > 1513653130.973720 221 2.0.0 Bye > > thunderstorm /run/dovecot/rawlogs # cat 20171219-141149.5633.1.out > 1513653109.109087 EHLO thunderstorm.reub.net > 1513653130.973351 QUIT > 1513653130.973829 QUIT > thunderstorm /run/dovecot/rawlogs # > > This with: > > # Write protocol logs for relay connection to this directory for debugging > #submission_relay_rawlog_dir > submission_relay_rawlog_dir = /run/dovecot/rawlogs/ > > Is this a separate but unrelated problem with rawlog support in this the > submission? I would have expected it to capture the full conversation > log including any protocol errors and failures like this. > > Reuben
Stephan Bosch
2017-Dec-23 20:11 UTC
dovecot-submission SMTP send error with Thunderbird (BODY=8BITMIME)
Op 12/23/2017 om 7:18 AM schreef Reuben Farrelly:> Hi, > > With latest 2.3 -git (and 2.3.0 release), I'm running into this error > with Thunderbird: > > "An error occurred while sending mail. The mail server responded: > 5.5.4 Unsupported mail BODY type. Please verify that your email > address is correct in your account settings and try again." > > This is fatal and means Thunderbird cannot use the submission service > - fortunately I can revert back to a native Postfix service which works. > > Here's a tcpdump of the conversation: > > thunderstorm /etc/dovecot/conf.d # tcpdump -A port 587 > > dropped privs to tcpdump > tcpdump: verbose output suppressed, use -v or -vv for full protocol > decode > listening on eth0, link-type EN10MB (Ethernet), capture size 262144 bytesI cannot reproduce this behavior so far. (ngrep -Wbyline produces more readable output)> Curiously enabling rawlog doesn't capture this error, which is why I > used tcpdump above.? The logs from it like this: > > thunderstorm /run/dovecot/rawlogs # cat 20171219-141149.5633.1.in > 1513653109.109030 220 thunderstorm.reub.net ESMTP Postfix (3.3-20171028) > 1513653109.109266 250-thunderstorm.reub.net > 1513653109.109266 250-PIPELINING > 1513653109.109266 250-SIZE 40960000 > 1513653109.109266 250-VRFY > 1513653109.109266 250-ETRN > 1513653109.109266 250-STARTTLS > 1513653109.109266 250-ENHANCEDSTATUSCODES > 1513653109.109266 250-8BITMIME > 1513653109.109266 250-DSN > 1513653109.109266 250 SMTPUTF8 > 1513653130.973720 221 2.0.0 Bye > > thunderstorm /run/dovecot/rawlogs # cat 20171219-141149.5633.1.out > 1513653109.109087 EHLO thunderstorm.reub.net > 1513653130.973351 QUIT > 1513653130.973829 QUIT > thunderstorm /run/dovecot/rawlogs #Double QUIT. That is a minor bug, but not related.> > This with: > > # Write protocol logs for relay connection to this directory for > debugging > #submission_relay_rawlog_dir > submission_relay_rawlog_dir = /run/dovecot/rawlogs/ > > Is this a separate but unrelated problem with rawlog support in this > the submission?? I would have expected it to capture the full > conversation log including any protocol errors and failures like this.No. This is the connection with the relay (backend MTA) server. Use the normal Dovecot rawlog facilities to capture protocol interaction with the client instead. Well, now we do know for sure that Dovecot is responsible for the error, since the interaction with the relay server shows no issues. I will continue experimenting a bit. I still have to actually try this with Thunderbird. Any other configuration I should know about (`dovecot -n`)? Regards, Stephan.
Reuben Farrelly
2017-Dec-24 06:54 UTC
dovecot-submission SMTP send error with Thunderbird (BODY=8BITMIME)
Hi again, On 24/12/2017 7:11 am, Stephan Bosch wrote:> Op 12/23/2017 om 7:18 AM schreef Reuben Farrelly: >> Hi, >> >> With latest 2.3 -git (and 2.3.0 release), I'm running into this error >> with Thunderbird: >> >> "An error occurred while sending mail. The mail server responded: >> 5.5.4 Unsupported mail BODY type. Please verify that your email >> address is correct in your account settings and try again." >> >> This is fatal and means Thunderbird cannot use the submission service >> - fortunately I can revert back to a native Postfix service which works. >> >> Here's a tcpdump of the conversation: >> >> thunderstorm /etc/dovecot/conf.d # tcpdump -A port 587 >> >> dropped privs to tcpdump >> tcpdump: verbose output suppressed, use -v or -vv for full protocol >> decode >> listening on eth0, link-type EN10MB (Ethernet), capture size 262144 bytes > > I cannot reproduce this behavior so far.The odd thing is, I can 100% of the time reproduce this with the client, but 100% not reproduce it if I put the commands in by hand, at least up to the MAIL FROM: part of the conversation. Here's the TB log: [Main Thread]: I/SMTP SMTP Connecting to: smtp.reub.net:587 [Main Thread]: I/SMTP SMTP entering state: 0 [Main Thread]: I/SMTP SMTP Response: 220 thunderstorm.reub.net Dovecot ready. [Main Thread]: I/SMTP SMTP entering state: 14 [Main Thread]: I/SMTP SMTP Send: EHLO [IPv6:2001:44b8:31d4:1311:c0c8:3064:a55b:ae82] [Main Thread]: I/SMTP SMTP entering state: 0 [Main Thread]: I/SMTP SMTP Response: 250-thunderstorm.reub.net [Main Thread]: I/SMTP SMTP entering state: 0 [Main Thread]: I/SMTP SMTP Response: 250-8BITMIME [Main Thread]: I/SMTP SMTP entering state: 0 [Main Thread]: I/SMTP SMTP Response: 250-AUTH PLAIN LOGIN [Main Thread]: I/SMTP SMTP entering state: 0 [Main Thread]: I/SMTP SMTP Response: 250-BURL imap [Main Thread]: I/SMTP SMTP entering state: 0 [Main Thread]: I/SMTP SMTP Response: 250-CHUNKING [Main Thread]: I/SMTP SMTP entering state: 0 [Main Thread]: I/SMTP SMTP Response: 250-ENHANCEDSTATUSCODES [Main Thread]: I/SMTP SMTP entering state: 0 [Main Thread]: I/SMTP SMTP Response: 250-SIZE [Main Thread]: I/SMTP SMTP entering state: 0 [Main Thread]: I/SMTP SMTP Response: 250-STARTTLS [Main Thread]: I/SMTP SMTP entering state: 0 [Main Thread]: I/SMTP SMTP Response: 250 PIPELINING [Main Thread]: I/SMTP SMTP entering state: 4 [Main Thread]: I/SMTP SMTP entering state: 21 [Main Thread]: D/SMTP SMTP auth: server caps 0x20338, pref 0x300, failed 0x0, avail caps 0x300 [Main Thread]: D/SMTP (GSSAPI = 0x800, CRAM = 0x2000, NTLM = 0x4000, MSN = 0x8000, PLAIN = 0x200, LOGIN = 0x100, EXTERNAL = 0x400) [Main Thread]: D/SMTP trying auth method 0x200 [Main Thread]: I/SMTP SMTP entering state: 16 [Main Thread]: D/SMTP SMTP AuthLoginStep1() for reuben at smtp.reub.net [Main Thread]: D/SMTP PLAIN auth [Main Thread]: I/SMTP Logging suppressed for this command (it probably contained authentication information) [Main Thread]: I/SMTP SMTP entering state: 0 [Main Thread]: I/SMTP SMTP Response: 235 2.7.0 Logged in. [Main Thread]: I/SMTP SMTP entering state: 18 [Main Thread]: D/SMTP SMTP Login response, code 235 [Main Thread]: I/SMTP SMTP entering state: 3 [Main Thread]: I/SMTP SMTP Send: MAIL FROM:<reuben at reub.net> BODY=8BITMIME SIZE=425 [Main Thread]: I/SMTP SMTP entering state: 0 [Main Thread]: I/SMTP SMTP Response: 555 5.5.4 Unsupported mail BODY type [Main Thread]: I/SMTP SMTP entering state: 5 [Main Thread]: I/SMTP SMTP Send: QUIT [Main Thread]: I/SMTP SMTP entering state: 0 [Main Thread]: I/SMTP SMTP entering state: 0 [Main Thread]: I/SMTP SMTP Response: 221 2.0.0 Bye [Main Thread]: I/SMTP SMTP entering state: 11 [Main Thread]: I/SMTP SMTP entering state: 12 [Main Thread]: I/SMTP SMTP connection error quitting 80004004, ignoring> (ngrep -Wbyline produces more readable output)Thanks. ngrep seems to hate IPv6 though, but after a bit of forcing IPv4 it started working (the output was the same as the tcpdump).> I will continue experimenting a bit. I still have to actually try this > with Thunderbird. Any other configuration I should know about (`dovecot > -n`)?I think that'd help. I'm using Thunderbird on Windows. This thread might be of interest: http://forums.mozillazine.org/viewtopic.php?f=39&t=2849171 https://bugzilla.mozilla.org/show_bug.cgi?id=1032302 It all seems to suggest that this could be a client side specific bit of quirkiness that dovecot submission is not handling. Config is up here: http://www.reub.net/files/dovecot/thunderstorm-dovecot.conf Thanks, Reuben
Possibly Parallel Threads
- dovecot-submission SMTP send error with Thunderbird (BODY=8BITMIME)
- dovecot-submission SMTP send error with Thunderbird (BODY=8BITMIME)
- dovecot-2.3 (-git) Warning and Fatal Compile Error
- Core Dumps with dovecot-2.2 -git as of 2.2.devel (eaf276b33)
- dovecot-2.3 (-git) Warning and Fatal Compile Error