Debugging Thunderbird

While hunting down issues with DKIM, as mentioned in a previous blog entry, we had to figure out how to make Thunderbird provide us with a log file. According to the docs, to debug Thunderbird you should export some environmental variables (I am using Linux here as the OS in this example. Adjust as needed):

# For bash shell (the default shell on most GNU/Linux systems):
export NSPR_LOG_MODULES=imap:5
export NSPR_LOG_FILE=/tmp/imap.log

Make your life easier and do it inside a script:

raub@desktop:/tmp$ cat thunderchicken
#!/bin/sh
# For bash shell (the default shell on most GNU/Linux systems):
export NSPR_LOG_MODULES=smtp:5
export NSPR_LOG_FILE=/tmp/smtp.log
thunderbird
raub@desktop:/tmp$

This way the environment variables you are setting only exist in the context of the script

raub@desktop:/tmp$ sh -x thunderchicken
+ export NSPR_LOG_MODULES=smtp:5
+ NSPR_LOG_MODULES=smtp:5
+ export NSPR_LOG_FILE=/tmp/smtp.log
+ NSPR_LOG_FILE=/tmp/smtp.log
+ thunderbird
[calBackendLoader] Using libical backend at /home/raub/.thunderbird/emfxtc69.default/extensions/
{e2fda1a4-762b-4020-b5ad-a41df1933103}/components/libical.manifest

If you do that, you will not have a beautiful log file you can then examine as you test things in Thunderbird:

raub@desktop:~$ ls -l /tmp/smtp.log
-rw-rw-r--. 1 raub raub 0 Jun 24 16:28 /tmp/smtp.log
raub@desktop:~$ ls -l /tmp/smtp.log
-rw-rw-r--. 1 raub raub 6464 Jun 24 16:29 /tmp/smtp.log
raub@desktop:~$

Email fun: 8BITMIME and DKIM body authentication failure

Like most of you who decided to read this post, we use DomainKeys Identified Mail (DKIM) in an attempt to keep email spoofing down. . We noticed that some of the emails we were receiving were marked as spam by spamassassin when they shouldn't. Looking at the email header we saw they were failing the DKIM body integrity test. The entries in the header file looks something like

Authentication-Results mail.example.com (amavisd-new); dkim=softfail 
(fail, body has been altered) header.i=@example.com

or

dkim=neutral (body hash did not verify).
dkim=fail (message has been altered) domainkeys=pass

That would increase the score of those legitimate emails just above the threshold, causing spamassassin to flag them as spam. After some investigating, we found out emails that contained characters above the original ASCII character set, such as Olivenöl, in the body of the message were failing. In other words, DKIM really does not like 8bit (specifically 8BITMIME) encoding.

I was able to duplicate that by sending an email to myself or to a gmail test account using our default mail client, Thunderbird. So I tried to manually (using netcat; telnet would have worked fine) create a properly configured 8Bit email using our SMTP server (As you can clearly see, our MX server (postfix) is setup to handle 8BITMIME):

raub@desktop:/tmp$ nc -t mail.example.com 25
220 mail.example.com Test Mail Server
EHLO desktop.example.com
250-mail.example.com
250-PIPELINING
250-SIZE
250-ETRN
250-STARTTLS
250-ENHANCEDSTATUSCODES
250-8BITMIME
250 DSN
MAIL FROM:<raub@desltop.example.com> BODY=8BITMIME
250 2.1.0 Ok
RCPT TO:<raub@example.com>
250 2.1.5 Ok
DATA
354 End data with <CR><LF>.<CR><LF>
From: "Mauricio Tavares" 
Subject: 8bit test
Date: Mon, 30 Jun 2014 11:10:05 -0400
MIME-Version: 1.0
Content-Transfer-Encoding: 8bit

Olivenöl

.
250 2.0.0 Ok: queued as 2BA1F80041
QUIT
221 2.0.0 Bye
raub@desktop:/tmp$

The above would work while using Thunderbird didn't. After setting Thunderbird to debug mode, we noticed it was not properly indicating the email was 8BITMIME, so postfix would treat it as a 7bit ASCII email and then DKIM would fail. The DKIM signatures of 8BITMIME mail may break unless all SMTP servers in the path implement and announce 8BITMIME support, and as shown above the mail clients do not lie. Since we cannot guarantee that is the case, it is better to down-convert to quoted-printable before DKIM signing.

Solution is to force the MTA to downconvert to 7bit. That can be done in postfix by creating a null filter in master.cf that is called before the rest of the filters. In other words, something like

smtp      inet  n       -       n       -       -       smtpd
   -o content_filter=smtp-downconvert:127.0.0.1:10027
[...]
smtp-downconvert  unix    -       -       -       -       2       smtp
   -o smtp_discard_ehlo_keywords=8bitmime,silent-discard
127.0.0.1:10027 inet  n       -       n       -       -       smtpd
   -o smtpd_authorized_xforward_hosts=127.0.0.1
   -o smtpd_client_restrictions=
   -o smtpd_helo_restrictions=
   -o smtpd_sender_restrictions=
   -o smtpd_relay_restrictions=
   -o smtpd_recipient_restrictions=permit_mynetworks,reject

should do the trick. If we restart the MX (postfix reload will do the trick) and send the test email again, the email now should show something like

Authentication-Results mail.example.com (amavisd-new); dkim=pass header.i=@example.com

in the header, which means DCKIM is successful and life is good... for now

I would like to thank Wietse Venema for pointing me on the right direction regarding downconverting.

Note: HELO vs EHLO

• HELO: Standard/Original SMTP (7-bit ASCII email) (RFC 821, 5321)
  
• EHLO: ESMTP (RFC 1869). Think Enhanced HELO; supports MIME and other exciting extensions. A quick discussion is found at http://cr.yp.to/smtp/ehlo.html.