Thunderbird sending delayed emails

My dad has, over the past few weeks, been having his emails delayed by as much as a week on his Onetel account. He has another which works fine. Both are through Thunderbird but it’s only the Onetel that gets the delays. He can mail his wife on a Hotmail account and his other email and they both get through normally. However outside of his own home they become delayed. He can send mail from the Onetel account directly and that’s fine, but for whatever reason when doing it through Thunderbird the delays happen.

I do have received delayed emails and he’s asked me to look through them in Notepad and / or look at their source code to see if I can work out what might be causing the delays. I like the idea but I’m not sure what I should be looking specifically for, so any help with this appreciated.

Thanks

Have you tried sending emails TO onetel? Is that any different? Does the email sit in the outbox or is the delay server side?

Yeah, I’ve replied to ones that have finally arrived after a couple of days. He gets them within a few minutes.
There was one that he sent using Onetel on Port 25 that I received quickly, but he tried again a few minutes later and I still haven’t received it (that was on the 9th). Since then I haven’t received any, so I’m due quite a few delayed ones to arrive in the next few days.

Hi, I’ve not used the one tell services.
Is this setup on Thunderbird using IMAP or POP3?
If it’s using POP3 then have you tried configuring the account in IMAP?
If it’s in Pop then it maybe due to some messages not been sync’d by Send/Receive at the time of sending?

I’ve a feeling he’s using POP3, I’ve asked him to send me his settings so I’m just waiting on that. I’ll ask him to see if he can try it on IMAP too. Would you be able to setup the same email with two accounts (POP3 and IMAP)?

The trouble is with sending emails being delayed correct?

If it is sending that is the problem, then pop or imap probably aren’t to blame since they are for retrieving emails from your mda which is probably not the mta (smtp/submission) that thunderbird (your mua) talks to to send mail.

1 Like

Yeah, he can receive them on his Onetel account as expected. It just takes days for others to receive them when he sends them.

Sending is the problem for him. This has been happening since December if I remember correctly.
He’s reinstalled Thunderbird but it didn’t help.

With sending emails there are at least two transactions that could be delayed. There is the smtp transaction between thunderbird and your father’s smtp mail server, and there is the smtp transaction between your father’s mail server and the recipient’s mail server (there could be multiple relays between the recipient’s mail server designated by the domain’s mx record and the recipient’s mailbox; but if it’s multiple recipients having problems, then it’s likely an issue somewhere on your father’s side).

My guess is that when your father sends an email with thunderbird, the recipient’s mail server soft bounces/grey lists the email (possibly because thunderbird is adding headers that make the recipient’s server mark it as spam) and then your father’s email server doesn’t try to resend the message for several days instead of waiting for a few minutes.

You can set thunderbird to log the smtp transaction between itself and your father’s mail server. https://wiki.mozilla.org/MailNews:Logging

You just set the two environment variables MOZ_LOG and MOZ_LOG_FILE or NSPR_LOG_MODULES and NSPR_LOG_FILE if you have an old version (55).

clifford@thinkpad:~$ export MOZ_LOG=SMTP:5,timestamp
clifford@thinkpad:~$ export MOZ_LOG_FILE=/tmp/smtp.log
clifford@thinkpad:~$ thunderbird

And send an email.

The log file is verbose:
2020-01-11 19:31:02.263893 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Connecting to: mail2.sluggishmail.com:587
2020-01-11 19:31:02.465161 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:02.465183 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 220 mail2.sluggishmail.com ESMTP
2020-01-11 19:31:02.465191 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 14
2020-01-11 19:31:02.465215 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Send: EHLO [IPv6:2600:8801:2907:b01:f91e:3f9a:e55:8ff3]
2020-01-11 19:31:02.549325 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:02.549337 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250-mail2.sluggishmail.com
2020-01-11 19:31:02.549344 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:02.549346 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250-PIPELINING
2020-01-11 19:31:02.549348 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:02.549350 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250-SIZE 104857600
2020-01-11 19:31:02.549351 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:02.549352 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250-ETRN
2020-01-11 19:31:02.549353 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:02.549355 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250-STARTTLS
2020-01-11 19:31:02.549357 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:02.549358 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250-ENHANCEDSTATUSCODES
2020-01-11 19:31:02.549359 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:02.549360 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250-8BITMIME
2020-01-11 19:31:02.549362 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:02.549363 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250 DSN
2020-01-11 19:31:02.549365 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 4
2020-01-11 19:31:02.549370 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 21
2020-01-11 19:31:02.549372 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Send: STARTTLS
2020-01-11 19:31:02.631315 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:02.631343 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 220 2.0.0 Ready to start TLS
2020-01-11 19:31:02.631363 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 19
2020-01-11 19:31:02.631395 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 14
2020-01-11 19:31:02.631424 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Send: EHLO [IPv6:2600:8801:2907:b01:f91e:3f9a:e55:8ff3]
2020-01-11 19:31:03.010697 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:03.010722 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250-mail2.sluggishmail.com
2020-01-11 19:31:03.010738 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:03.010743 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250-PIPELINING
2020-01-11 19:31:03.010749 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:03.010753 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250-SIZE 104857600
2020-01-11 19:31:03.010758 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:03.010761 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250-ETRN
2020-01-11 19:31:03.010765 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:03.010769 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250-AUTH PLAIN LOGIN
2020-01-11 19:31:03.010773 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:03.010777 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250-AUTH=PLAIN LOGIN
2020-01-11 19:31:03.010781 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:03.010894 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250-ENHANCEDSTATUSCODES
2020-01-11 19:31:03.010901 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:03.010905 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250-8BITMIME
2020-01-11 19:31:03.010910 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:03.010914 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250 DSN
2020-01-11 19:31:03.010924 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 4
2020-01-11 19:31:03.010942 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 21
2020-01-11 19:31:03.010948 UTC - [(null) 14901: Main Thread]: D/SMTP SMTP auth: server caps 0x20334, pref 0x300, failed 0x0, avail caps 0x300
2020-01-11 19:31:03.010954 UTC - [(null) 14901: Main Thread]: D/SMTP (GSSAPI = 0x800, CRAM = 0x2000, NTLM = 0x4000, MSN =  0x8000, PLAIN = 0x200, LOGIN = 0x100, EXTERNAL = 0x400)
2020-01-11 19:31:03.010957 UTC - [(null) 14901: Main Thread]: D/SMTP trying auth method 0x200
2020-01-11 19:31:03.010961 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 16
2020-01-11 19:31:03.010980 UTC - [(null) 14901: Main Thread]: D/SMTP SMTP AuthLoginStep1() for [email protected]@mail2.sluggishmail.com
2020-01-11 19:31:03.019301 UTC - [(null) 14901: Main Thread]: D/SMTP PLAIN auth
2020-01-11 19:31:03.019323 UTC - [(null) 14901: Main Thread]: I/SMTP Logging suppressed for this command (it probably contained authentication information)
2020-01-11 19:31:03.107254 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:03.107276 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 235 2.7.0 Authentication successful
2020-01-11 19:31:03.107292 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 18
2020-01-11 19:31:03.107296 UTC - [(null) 14901: Main Thread]: D/SMTP SMTP Login response, code 235
2020-01-11 19:31:03.107299 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 3
2020-01-11 19:31:03.108135 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Send: MAIL FROM:<[email protected]> BODY=8BITMIME SIZE=494
2020-01-11 19:31:03.201420 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:03.201445 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250 2.1.0 Ok
2020-01-11 19:31:03.201462 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 5
2020-01-11 19:31:03.201487 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Send: RCPT TO:<[email protected]>
2020-01-11 19:31:03.334286 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:03.334314 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250 2.1.5 Ok
2020-01-11 19:31:03.334333 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 6
2020-01-11 19:31:03.334340 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Send: DATA
2020-01-11 19:31:03.413470 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:03.413498 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 354 End data with <CR><LF>.<CR><LF>
2020-01-11 19:31:03.413516 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 7
2020-01-11 19:31:03.415036 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 8
2020-01-11 19:31:03.415579 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Send: .
2020-01-11 19:31:03.509870 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:03.509891 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 250 2.0.0 Ok: queued as 41DB31456F5
2020-01-11 19:31:03.509907 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 9
2020-01-11 19:31:03.510437 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Send: QUIT
2020-01-11 19:31:03.510460 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:03.619938 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 0
2020-01-11 19:31:03.619965 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP Response: 221 2.0.0 Bye
2020-01-11 19:31:03.620082 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 10
2020-01-11 19:31:03.634664 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP entering state: 12
2020-01-11 19:31:03.634719 UTC - [(null) 14901: Main Thread]: I/SMTP SMTP connection error quitting 804b0002, ignoring 
But it follows a straightforward pattern:
  1. Client Connects: SMTP Connecting to: mail2.sluggishmail.com:587
  2. Server says hello: SMTP Response: 220 mail2.sluggishmail.com ESMTP
  3. Client says hello: Send: EHLO [IPv6:2600:8801:2907:b01:f91e:3f9a:e55:8ff3]
  4. Server presents a bunch of options, none of which is AUTH.
  5. Client choses STARTTLS to encrypt connection: Send: STARTTLS
  6. Server then presents an AUTH option
  7. Client transmits credentials.
  8. After successful authentication, clients describes the email: SMTP Send: MAIL FROM:<[email protected]> BODY=8BITMIME SIZE=494
  9. SMTP Send: RCPT TO:<[email protected]>
  10. SMTP Send: DATA
  11. client ends emailResponse: 354 End data with <CR><LF>.<CR><LF>
  12. client asks server to send: SMTP Send: .
  13. Server responds that it has queued the email for sending Response: 250 2.0.0 Ok: queued as 41DB31456F5

If you don’t see the Response: 250 2.0.0 Ok: queued as 41DB31456F5 then something went wrong.

But if the problem is the recipient’s soft bouncing the email and then your dad’s server taking a long time to resend, you would need the logs on one of those server.

They would look something like:
Jan 11 11:31:02 mail-server-2 postfix/submission/smtpd[19948]: connect from unknown[fd00:8000::1]
Jan 11 11:31:02 mail-server-2 postfix/submission/smtpd[19948]: Anonymous TLS connection established from unknown[fd00:8000::1]: TLSv1.3 with cipher TLS_AES_128_GCM_SHA256 (128/128 bits)
Jan 11 11:31:03 mail-server-2 postfix/submission/smtpd[19948]: 41DB31456F5: client=unknown[fd00:8000::1], sasl_method=PLAIN, [email protected]
Jan 11 11:31:03 mail-server-2 postfix/cleanup[19950]: 41DB31456F5: message-id=<[email protected]>
Jan 11 11:31:03 mail-server-2 postfix/qmgr[499]: 41DB31456F5: from=<[email protected]>, size=925, nrcpt=1 (queue active)
Jan 11 11:31:03 mail-server-2 postfix/submission/smtpd[19948]: disconnect from unknown[fd00:8000::1] ehlo=2 starttls=1 auth=1 mail=1 rcpt=1 data=1 quit=1 commands=8
Jan 11 11:31:04 mail-server-2 postfix/smtp[19951]: 41DB31456F5: to=<[email protected]>, relay=verifier.port25.com[2600:1f14:a73:9b01:d769:5be1:de28:5251]:25, delay=0.94, delays=0.31/0.01/0.35/0.27, dsn=2.6.0, status=sent (250 2.6.0 message received)
Jan 11 11:31:04 mail-server-2 postfix/qmgr[499]: 41DB31456F5: removed

The important line is Jan 11 11:31:04 mail-server-2 postfix/smtp[19951]: 41DB31456F5: to=<[email protected]>, relay=verifier.port25.com[2600:1f14:a73:9b01:d769:5be1:de28:5251]:25, delay=0.94, delays=0.31/0.01/0.35/0.27, dsn=2.6.0, status=sent (250 2.6.0 message received)

and the status=sent (250 2.6.0 message received). A soft bounce would be an error in the 400s. A hard error would be in the 500s.

If you can’t get to those logs, the next best thing might be to send an email to [email protected]it will bounce the email back with all the processing the recipient server did, including the spam score, which might be triggering grey-listing of your father’s emails.

Thanks very much for all this but I can’t even get a verbose to appear after creating the batch file. I’ll have to understand this myself before I pass it onto him, I doubt he’ll be able to make sense out of it.

I’m putting in my email instead of clifford@thinkpad, but no log file is being created in /tmp. I also tried the one in the wiki but nothing happens when I run / open it. Sorry, I can’t understand what I’m doing wrong.

The clifford@thinkpad:~$ is the prompt for the terminal. So I type in the command export MOZ_LOG=SMTP:5,timestamp, hit enter, typed in export MOZ_LOG_FILE=/tmp/smtp.log, hit enter, and then typed in thunderbird, and hit enter to open thunderbid.

Does batch file mean you are on windows? If so your prompt would look something like:

C:\Users\Clifford>

and then you would type in set MOZ_LOG=SMTP:5,timestamp, hit enter, type in set MOZ_LOG_FILE=%USERPROFILE%\Desktop\smtp.log, hit enter, and then type in "%ProgramFiles(x86)%\Mozilla Thunderbird\thunderbird.exe", and hit enter to run thunderbird.

So the whole thing on windows would look like:

And that should save the log to your desktop.

But you don’t need the log to send the email to [email protected].

That address will immediately reply once it receives an email and it will show you if your messages are being marked as spam (at least for its server).

1 Like

Amazing, got the log file working now that you broke it down for me.
Yeah, we’re both on Windows. So he should be able to get this working and also see what that link says about his email server. I’ve emailed him a link to this thread so I’ll have to wait and see how he gets on and go from there.
Thanks again.

1 Like

So I realised my dad has been using the btinternet.smtp for the onetel email account for maybe years. Turns out he had problems with the account years ago, so switched the smtp from Onetel to BT.

I then read that TalkTalk (UK) bought Onetel back in 2007 and I’m finding community forums with threads about Onetel issues and that those email accounts will be ‘upgraded’ soon. One quote from the community admin:

Onetel is an insecure legacy email platform

It makes me think that TalkTalk’s tranformation of those email accounts may be contributing to his delay issues. He hasn’t got around to testing an email yet sorry.

1 Like

Okay, so he mailed the authenticator verifier and amongst other info was the summary and the results:

SPF check: neutral
“iprev” check: pass
DKIM check: none
SpamAssassin check: ham

Spam Assassin Check Details
Result: ham (1.0 points, 5.0 required)
0.8 BAYES_50 BODY: Bayes spam probability is 40 to 60%

DKIM Results

none: The message was not signed.

pass: The message was signed, the signature or signatures were
acceptable to the ADMD, and the signature(s) passed verification
tests.

fail: The message was signed and the signature or signatures were
acceptable to the ADMD, but they failed the verification test(s).

policy: The message was signed, but some aspect of the signature or
signatures was not acceptable to the ADMD.

neutral: The message was signed, but the signature or signatures
contained syntax errors or were not otherwise able to be
processed. This result is also used for other failures not
covered elsewhere in this list.

temperror: The message could not be verified due to some error that
is likely transient in nature, such as a temporary inability to
retrieve a public key. A later attempt may produce a final
result.

permerror: The message could not be verified due to some error that
is unrecoverable, such as a required header field being absent. A
later attempt is unlikely to produce a final result.

SPF Results

none: Either (a) no syntactically valid DNS domain name was extracted from
the SMTP session that could be used as the one to be authorized, or
(b) no SPF records were retrieved from the DNS.

neutral: The ADMD has explicitly stated that it is not asserting whether
the IP address is authorized.

pass: An explicit statement that the client is authorized to inject mail
with the given identity.

fail: An explicit statement that the client is not authorized to use the
domain in the given identity.

softfail: A weak statement by the publishing ADMD that the host is probably
not authorized. It has not published a stronger, more definitive policy
that results in a “fail”.

temperror: The SPF verifier encountered a transient (generally DNS) error
while performing the check. A later retry may succeed without further
DNS operator action.

permerror: The domain’s published records could not be correctly interpreted.
This signals an error condition that definitely requires DNS operator
intervention to be resolved.

“iprev” Results

pass: The DNS evaluation succeeded, i.e., the “reverse” and
“forward” lookup results were returned and were in agreement.

fail: The DNS evaluation failed. In particular, the “reverse” and
“forward” lookups each produced results, but they were not in
agreement, or the “forward” query completed but produced no
result, e.g., a DNS RCODE of 3, commonly known as NXDOMAIN, or an
RCODE of 0 (NOERROR) in a reply containing no answers, was
returned.

temperror: The DNS evaluation could not be completed due to some
error that is likely transient in nature, such as a temporary DNS
error, e.g., a DNS RCODE of 2, commonly known as SERVFAIL, or
other error condition resulted. A later attempt may produce a
final result.

permerror: The DNS evaluation could not be completed because no PTR
data are published for the connecting IP address, e.g., a DNS
RCODE of 3, commonly known as NXDOMAIN, or an RCODE of 0 (NOERROR)
in a reply containing no answers, was returned. This prevented
completion of the evaluation. A later attempt is unlikely to
produce a final result.

So with that high ham score I assume cburn11 was right about all my dad’s mail being seen as spam and being put on hold.

:scream: My dad and I can’t get the log file to work now. The file keeps coming up blank. I can’t see what I’m missing / doing wrong.

I wouldn’t worry too much about the thunderbird log. Since your email to port25.com was delivered, the problem is probably not between thunderbird and your email server.

That leaves the transaction between your email server and the email server for the recipient’s of the delayed messages.

Can you view the entire email (source, header and all) of the emails that were delivered to you late? Maybe the recipient server added the spam scoring in the headers.

Sorry, got it. I forgot to close Thunderbird before running the last line.

I can view the source code of the latest mails. I can’t see any spam scoring in the code though. Is it just X-Spam and a number that I’m looking for?

It depends on what the receiving server added, it may not be anything.

I can’t see anything relating to spam or even anything to do with them being delayed. My dad got me to look at them before I posted here. All I could see was

dmarc=fail

that seemed to be in all the delayed mails, but it also appeared in other mails he sent that weren’t delayed.

If it’s things like failed dmarc or spam scoring that is causing recipient servers to soft bounce the emails, then, as far as I know, your remedy is to let onetel support know about your issues and hope they can do something.