--- Begin Message ---
Package: thunderbird
Version: 1:68.4.1-1~deb10u1
Severity: normal
Dear Maintainer,
I'm trying to improve the account creation for a mail server setup of
mine. To this end, I setup and configured automx2 on the server, and
now I'm trying to get Thunderbird to use it. automx2 implements
Mozilla's autoconfiguration protocol:
https://wiki.mozilla.org/Thunderbird:Autoconfiguration:ConfigFileFormat
Sadly, Thunderbird's account creation wizard fails to use this
information. I increased the log level on
mail.wizard.logging.{console,dump} to "All", and captured a log of
this interaction (see below).
The curious thing is that the autoconfiguration actually seems to
succeed:
2020-03-01 10:37:43 mail.setup INFO found config:
Incoming: imap, harrington.uberspace.de:993, SSL, auth: plain, username:
(redacted), password: not set
Outgoing: smtp, harrington.uberspace.de:587, STARTTLS, auth: plain, username:
(redacted), password: not set
2
2020-03-01 10:37:43 mail.setup INFO Cannot contact server
2
This is the right information, I don't understand why it says "Cannot
contact server":
% socat - tcp:harrington.uberspace.de:587
220 harrington.uberspace.de ESMTP
^C
% socat - openssl:harrington.uberspace.de:993
* OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE
AUTH=PLAIN] Dovecot ready.
^C
This information is coming from the first source that Thunderbird
tries:
2020-03-01 10:37:42 mail.setup INFO Requesting
<https://autoconfig.probier.email/mail/config-v1.1.xml>
2
% curl
https://autoconfig.probier.email/mail/[email protected]
<clientConfig version="1.1"><emailProvider id="automx2-23425"><identity
/><domain>probier.email</domain><displayName>probier.email</displayName><displayShortName>probier.email</displayShortName><incomingServer
type="imap"><hostname>harrington.uberspace.de</hostname><port>993</port><socketType>SSL</socketType><username>%EMAILADDRESS%</username><authentication>plain</authentication></incomingServer><outgoingServer
type="smtp"><hostname>harrington.uberspace.de</hostname><port>587</port><socketType>STARTTLS</socketType><username>%EMAILADDRESS%</username><authentication>plain</authentication></outgoingServer></emailProvider></clientConfig>
Thunderbird then goes on to try Microsoft's autodiscover protocol,
which should also be implemented by automx2, but that fails (haven't
looked into this deeper). Finally, it tries some heuristic, which
mistakenly uses "probier.email" as the server name (which kinda works,
modulo TLS cert common name).
Manual configuration of the account works fine.
I expect autoconfiguration to work using Mozilla's own protocol. If
anything goes wrong with that (maybe automx2 doesn't correctly
implement the protocol?), I'd like to see a more informative error
message in the log.
Feel free to test this with [email protected].
*** bugs/thunderbird.all.log
2020-03-01 10:36:59 mail.setup INFO Initializing setup wizard
2
2020-03-01 10:36:59 mail.setup INFO Email account setup dialog
loaded.
2
2020-03-01 10:36:59 mail.setup INFO switching to UI mode start
2
2020-03-01 10:37:42 mail.setup INFO findConfig()
2
2020-03-01 10:37:42 mail.setup INFO switching to UI mode find-config
2
2020-03-01 10:37:42 mail.setup WARN spinner start
looking_up_settings
2
2020-03-01 10:37:42 mail.setup INFO status msg: Looking up
configuration…
2
2020-03-01 10:37:42 mail.setup INFO Requesting
<https://autoconfig.probier.email/mail/config-v1.1.xml>
2
2020-03-01 10:37:42 mail.setup INFO Requesting
<https://probier.email/.well-known/autoconfig/mail/config-v1.1.xml>
2
2020-03-01 10:37:42 mail.setup INFO Requesting
<http://autoconfig.probier.email/mail/config-v1.1.xml>
2
2020-03-01 10:37:42 mail.setup INFO Requesting
<http://probier.email/.well-known/autoconfig/mail/config-v1.1.xml>
2
2020-03-01 10:37:42 mail.setup INFO Requesting
<https://live.thunderbird.net/autoconfig/v1.1/probier.email>
2
2020-03-01 10:37:42 mail.setup INFO Requesting
<https://autodiscover.probier.email/autodiscover/autodiscover.xml>
2
2020-03-01 10:37:42 mail.setup INFO Requesting
<https://probier.email/autodiscover/autodiscover.xml>
2
2020-03-01 10:37:42 mail.setup INFO Requesting
<http://autodiscover.probier.email/autodiscover/autodiscover.xml>
2
2020-03-01 10:37:42 mail.setup INFO call 0 took 19ms and failed
with local file not found
2
2020-03-01 10:37:42 mail.setup INFO getmx took 74ms
2
2020-03-01 10:37:42 mail.setup INFO call 3 took 75ms and failed
with [Exception... "Component returned failure code: 0x804b0050
(NS_ERROR_INSUFFICIENT_DOMAIN_LEVELS)
[nsIEffectiveTLDService.getBaseDomainFromHost]" nsresult: "0x804b0050
(NS_ERROR_INSUFFICIENT_DOMAIN_LEVELS)" location: "JS frame ::
chrome://messenger/content/accountcreation/fetchConfig.js ::
fetchConfigForMX/sucAbortable.current< :: line 189" data: no]
2
2020-03-01 10:37:43 mail.setup INFO call 1 took 135ms and failed
with 404 Not Found at
<https://probier.email/.well-known/autoconfig/mail/config-v1.1.xml>
2
2020-03-01 10:37:43 mail.setup INFO call 3 took 136ms and failed
with 404 Not Found at
<http://probier.email/.well-known/autoconfig/mail/config-v1.1.xml>
2
Exception { name: "NS_ERROR_INSUFFICIENT_DOMAIN_LEVELS", message: "Component
returned failure code: 0x804b0050 (NS_ERROR_INSUFFICIENT_DOMAIN_LEVELS)
[nsIEffectiveTLDService.getBaseDomainFromHost]", result: 2152398928, filename:
"chrome://messenger/content/accountcreation/emailWizard.js", lineNumber: 1150,
columnNumber: 0, data: null, stack:
"_makeHostDisplayString@chrome://messenger/content/accountcreation/emailWizard.js:1150:34\ndisplayConfigResult@chrome://messenger/content/accountcreation/emailWizard.js:1193:7\nsuccessCallback@chrome://messenger/content/accountcreation/emailWizard.js:843:14\ngetAddonsList@chrome://messenger/content/accountcreation/exchangeAutoDiscover.js:377:5\nfoundConfig@chrome://messenger/content/accountcreation/emailWizard.js:846:23\nfindConfig/this._abortable<@chrome://messenger/content/accountcreation/emailWizard.js:630:14\nPriorityOrderAbortable/<@chrome://messenger/content/accountcreation/util.js:483:9\n_notifyFinished@chrome://messenger/content/accountcreation/util.js:331:9\nsuccessCallback/<@chrome://messenger/content/accountcreation/util.js:391:31\nfetchConfigFromISP/priority<@chrome://messenger/content/accountcreation/fetchConfig.js:108:12\nPriorityOrderAbortable/<@chrome://messenger/content/accountcreation/util.js:483:9\n_notifyFinished@chrome://messenger/content/accountcreation/util.js:331:9\nsuccessCallback/<@chrome://messenger/content/accountcreation/util.js:391:31\n_response@chrome://messenger/content/accountcreation/fetchhttp.js:312:16\nstart/request.onload@chrome://messenger/content/accountcreation/fetchhttp.js:214:10\n",
location: XPCWrappedNative_NoHelper }
util.js:487:17
2020-03-01 10:37:43 mail.setup INFO call 0 took 153ms and succeeded
at <https://autoconfig.probier.email/mail/config-v1.1.xml>
2
2020-03-01 10:37:43 mail.setup INFO call 1 took 155ms and succeeded
2
2020-03-01 10:37:43 mail.setup INFO status msg: Configuration found
at email provider
2
2020-03-01 10:37:43 mail.setup WARN all spinner stop
found_settings_isp
2
2020-03-01 10:37:43 mail.setup INFO found config:
Incoming: imap, harrington.uberspace.de:993, SSL, auth: plain, username:
(redacted), password: not set
Outgoing: smtp, harrington.uberspace.de:587, STARTTLS, auth: plain, username:
(redacted), password: not set
2
2020-03-01 10:37:43 mail.setup INFO Cannot contact server
2
2020-03-01 10:37:43 mail.setup INFO call 2 took 153ms and failed
with Another higher call succeeded at
<http://autoconfig.probier.email/mail/config-v1.1.xml>
2
2020-03-01 10:37:43 mail.setup INFO call 0 took 152ms and failed
with 400 Bad Request at
<https://autodiscover.probier.email/autodiscover/autodiscover.xml>
2
2020-03-01 10:37:43 mail.setup INFO call 1 took 211ms and failed
with 404 Not Found at <https://probier.email/autodiscover/autodiscover.xml>
2
2020-03-01 10:37:43 mail.setup INFO Call to
<http://autodiscover.probier.email/autodiscover/autodiscover.xml> was
redirected to
<https://autodiscover.probier.email/autodiscover/autodiscover.xml>, and failed.
Re-trying the new URL with authentication again.
2
2020-03-01 10:37:43 mail.setup INFO call 2 took 250ms and failed
with 400 Bad Request at
<https://autodiscover.probier.email/autodiscover/autodiscover.xml>
2
2020-03-01 10:37:43 mail.setup INFO call 4 took 253ms and failed
with 400 Bad Request
2
Handler function threw an exception: [Exception... "Component returned failure
code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsICacheInfoChannel.isRacing]"
nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)" location: "JS frame ::
resource://devtools/server/actors/network-monitor/network-response-listener.js
:: NetworkResponseListener.prototype._getSecurityInfo< :: line 334" data: no]
Stack:
NetworkResponseListener.prototype._getSecurityInfo<@resource://devtools/server/actors/network-monitor/network-response-listener.js:334:26
exports.makeInfallible/<@resource://devtools/shared/ThreadSafeDevToolsUtils.js:111:22
onStartRequest@resource://devtools/server/actors/network-monitor/network-response-listener.js:226:10
Line: 334, column: 0 ThreadSafeDevToolsUtils.js:90:13
2020-03-01 10:37:43 mail.setup INFO call 2 took 556ms and failed
with 404 Not Found at
<https://live.thunderbird.net/autoconfig/v1.1/probier.email>
2
2020-03-01 10:37:43 mail.setup WARN spinner start
looking_up_settings_guess
2
2020-03-01 10:37:43 mail.setup INFO status msg: Looking up
configuration: Trying common server names
2
2020-03-01 10:37:43 mail.wizard INFO created host detector
2
2020-03-01 10:37:43 mail.wizard INFO doing auto detect for protocol
-1, domain probier.email, (exactly: false), port -1, ssl -1
2020-03-01 10:37:43 mail.wizard INFO doing auto detect for protocol
2, domain probier.email, (exactly: false), port -1, ssl -1
2020-03-01 10:37:43 mail.wizard INFO imap.probier.email:143 ssl=2
imap: initializing probe...
2020-03-01 10:37:43 mail.setup INFO imap.probier.email:143 ssl=3
imap: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO mail.probier.email:143 ssl=2
imap: initializing probe...
2020-03-01 10:37:43 mail.wizard INFO probier.email:143 ssl=2 imap:
initializing probe...
2020-03-01 10:37:43 mail.wizard INFO pop3.probier.email:110 ssl=2
pop3: initializing probe...
2020-03-01 10:37:43 mail.wizard INFO pop.probier.email:110 ssl=2
pop3: initializing probe...
2020-03-01 10:37:43 mail.wizard INFO mail.probier.email:110 ssl=2
pop3: initializing probe...
2020-03-01 10:37:43 mail.wizard INFO probier.email:110 ssl=2 pop3:
initializing probe...
2020-03-01 10:37:43 mail.wizard INFO imap.probier.email:143 ssl=0
imap: initializing probe...
2020-03-01 10:37:43 mail.wizard INFO mail.probier.email:143 ssl=0
imap: initializing probe...
2020-03-01 10:37:43 mail.wizard INFO probier.email:143 ssl=0 imap:
initializing probe...
2020-03-01 10:37:43 mail.wizard INFO pop3.probier.email:110 ssl=0
pop3: initializing probe...
2020-03-01 10:37:43 mail.wizard INFO pop.probier.email:110 ssl=0
pop3: initializing probe...
2020-03-01 10:37:43 mail.wizard INFO mail.probier.email:110 ssl=0
pop3: initializing probe...
2020-03-01 10:37:43 mail.wizard INFO probier.email:110 ssl=0 pop3:
initializing probe...
2020-03-01 10:37:43 mail.wizard INFO smtp.probier.email:587 ssl=2
smtp: initializing probe...
2020-03-01 10:37:43 mail.setup INFO smtp.probier.email:587 ssl=3
smtp: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO smtp.probier.email:25 ssl=2
smtp: initializing probe...
2020-03-01 10:37:43 mail.wizard INFO mail.probier.email:587 ssl=2
smtp: initializing probe...
2020-03-01 10:37:43 mail.wizard INFO mail.probier.email:25 ssl=2
smtp: initializing probe...
2020-03-01 10:37:43 mail.wizard INFO probier.email:587 ssl=2 smtp:
initializing probe...
2020-03-01 10:37:43 mail.wizard INFO probier.email:25 ssl=2 smtp:
initializing probe...
2020-03-01 10:37:43 mail.wizard INFO smtp.probier.email:587 ssl=0
smtp: initializing probe...
2020-03-01 10:37:43 mail.wizard INFO smtp.probier.email:25 ssl=0
smtp: initializing probe...
2020-03-01 10:37:43 mail.wizard INFO mail.probier.email:587 ssl=0
smtp: initializing probe...
2020-03-01 10:37:43 mail.wizard INFO mail.probier.email:25 ssl=0
smtp: initializing probe...
2020-03-01 10:37:43 mail.wizard INFO probier.email:587 ssl=0 smtp:
initializing probe...
2020-03-01 10:37:43 mail.wizard INFO probier.email:25 ssl=0 smtp:
initializing probe...
2020-03-01 10:37:43 mail.setup INFO pop3.probier.email:110 ssl=3
pop3: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO pop3.probier.email:110 ssl=2
pop3: no data
2020-03-01 10:37:43 mail.setup INFO pop3.probier.email:110 ssl=1
pop3: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO pop3.probier.email:110 ssl=0
pop3: no data
2020-03-01 10:37:43 mail.setup INFO pop.probier.email:110 ssl=3
pop3: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO pop.probier.email:110 ssl=2
pop3: no data
2020-03-01 10:37:43 mail.setup INFO pop.probier.email:110 ssl=1
pop3: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO pop.probier.email:110 ssl=0
pop3: no data
2020-03-01 10:37:43 mail.setup INFO imap.probier.email:143 ssl=3
imap: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO imap.probier.email:143 ssl=2
imap: no data
2020-03-01 10:37:43 mail.setup INFO imap.probier.email:143 ssl=1
imap: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO imap.probier.email:143 ssl=0
imap: no data
2020-03-01 10:37:43 mail.setup INFO mail.probier.email:143 ssl=3
imap: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO mail.probier.email:143 ssl=2
imap: no data
2020-03-01 10:37:43 mail.setup INFO mail.probier.email:110 ssl=3
pop3: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO mail.probier.email:110 ssl=2
pop3: no data
2020-03-01 10:37:43 mail.setup INFO mail.probier.email:143 ssl=1
imap: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO mail.probier.email:143 ssl=0
imap: no data
2020-03-01 10:37:43 mail.setup INFO mail.probier.email:110 ssl=1
pop3: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO mail.probier.email:110 ssl=0
pop3: no data
2020-03-01 10:37:43 mail.setup INFO mail.probier.email:587 ssl=3
smtp: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO mail.probier.email:587 ssl=2
smtp: no data
2020-03-01 10:37:43 mail.setup INFO mail.probier.email:25 ssl=3
smtp: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO mail.probier.email:25 ssl=2
smtp: no data
2020-03-01 10:37:43 mail.setup INFO mail.probier.email:587 ssl=1
smtp: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO mail.probier.email:587 ssl=0
smtp: no data
2020-03-01 10:37:43 mail.setup INFO mail.probier.email:25 ssl=1
smtp: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO mail.probier.email:25 ssl=0
smtp: no data
2020-03-01 10:37:43 mail.setup INFO smtp.probier.email:587 ssl=3
smtp: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO smtp.probier.email:587 ssl=2
smtp: no data
2020-03-01 10:37:43 mail.setup INFO smtp.probier.email:25 ssl=3
smtp: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO smtp.probier.email:25 ssl=2
smtp: no data
2020-03-01 10:37:43 mail.setup INFO smtp.probier.email:587 ssl=1
smtp: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO smtp.probier.email:587 ssl=0
smtp: no data
2020-03-01 10:37:43 mail.setup INFO smtp.probier.email:25 ssl=1
smtp: progress callback
2
2020-03-01 10:37:43 mail.wizard INFO smtp.probier.email:25 ssl=0
smtp: no data
2020-03-01 10:37:43 mail.setup INFO probier.email:143 ssl=3 imap:
progress callback
2
2020-03-01 10:37:43 mail.wizard INFO probier.email:143 ssl=2 imap:
wiredata: * OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE
IDLE STARTTLS LOGINDISABLED] Dovecot ready.
* CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE STARTTLS
LOGINDISABLED
1 OK Pre-login capabilities listed, post-login capabilities have more.
* BYE Logging out
2 OK Logout completed.
2020-03-01 10:37:43 mail.wizard INFO probier.email:143 ssl=2 imap:
success
2020-03-01 10:37:43 mail.setup INFO probier.email:110 ssl=3 pop3:
progress callback
2
2020-03-01 10:37:43 mail.wizard INFO probier.email:110 ssl=2 pop3:
wiredata: +OK Dovecot ready.
+OK
CAPA
TOP
UIDL
RESP-CODES
PIPELINING
AUTH-RESP-CODE
STLS
SASL
.
+OK Logging out
2020-03-01 10:37:43 mail.wizard INFO probier.email:110 ssl=2 pop3:
success
2020-03-01 10:37:43 mail.setup INFO CHOOSING imap
probier.email:143, auth method 3, SSL 3
2
2020-03-01 10:37:43 mail.setup INFO CHOOSING pop3
probier.email:110, auth method 3, SSL 3
2
2020-03-01 10:37:43 mail.setup INFO probier.email:143 ssl=3 imap:
progress callback
2
2020-03-01 10:37:43 mail.setup INFO probier.email:587 ssl=3 smtp:
progress callback
2
2020-03-01 10:37:43 mail.wizard INFO probier.email:587 ssl=2 smtp:
wiredata: 220 harrington.uberspace.de ESMTP
250-harrington.uberspace.de
250-PIPELINING
250-8BITMIME
250-AUTH LOGIN PLAIN
250-STARTTLS
250 X-NOTHING
221 harrington.uberspace.de
2020-03-01 10:37:43 mail.wizard INFO probier.email:587 ssl=2 smtp:
success
2020-03-01 10:37:43 mail.setup INFO CHOOSING smtp
probier.email:587, auth method 3, SSL 3
2
2020-03-01 10:37:43 mail.setup INFO probier.email:587 ssl=3 smtp:
progress callback
2
2020-03-01 10:37:43 mail.setup INFO found config:
Incoming: imap, probier.email:143, STARTTLS, auth: plain, username: (redacted),
password: not set
Outgoing: smtp, probier.email:587, STARTTLS, auth: plain, username: (redacted),
password: not set
Incoming alt: pop3, probier.email:110, STARTTLS, auth: plain, username:
(redacted), password: not set
2
2020-03-01 10:37:43 mail.setup INFO switching to UI mode result
2
2020-03-01 10:37:43 mail.setup INFO status msg: Configuration found
by trying common server names
2
2020-03-01 10:37:43 mail.setup WARN all spinner stop
found_settings_guess
2
-- System Information:
Debian Release: 10.3
APT prefers stable
APT policy: (990, 'stable'), (500, 'unstable-debug'), (500, 'testing-debug'),
(500, 'stable-debug'), (500, 'proposed-updates-debug'), (500, 'unstable'),
(500, 'testing'), (1, 'experimental')
Architecture: amd64 (x86_64)
Foreign Architectures: i386
Kernel: Linux 4.19.0-8-amd64 (SMP w/4 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8) (ignored: LC_ALL
set to en_US.UTF-8), LANGUAGE=en_US.UTF-8 (charmap=UTF-8) (ignored: LC_ALL set
to en_US.UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled
Versions of packages thunderbird depends on:
ii debianutils 4.8.6.1
ii fontconfig 2.13.1-2
ii libatk1.0-0 2.30.0-2
ii libc6 2.28-10
ii libcairo-gobject2 1.16.0-4
ii libcairo2 1.16.0-4
ii libdbus-1-3 1.12.16-1
ii libdbus-glib-1-2 0.110-4
ii libevent-2.1-6 2.1.8-stable-4
ii libffi6 3.2.1-9
ii libfontconfig1 2.13.1-2
ii libfreetype6 2.9.1-3+deb10u1
ii libgcc1 1:8.3.0-6
ii libgdk-pixbuf2.0-0 2.38.1+dfsg-1
ii libglib2.0-0 2.58.3-2+deb10u2
ii libgtk-3-0 3.24.5-1
ii libgtk2.0-0 2.24.32-3
ii libjsoncpp1 1.7.4-3
ii libpango-1.0-0 1.42.4-7~deb10u1
ii libstartup-notification0 0.12-6
ii libstdc++6 8.3.0-6
ii libvpx5 1.7.0-3+deb10u1
ii libx11-6 2:1.6.7-1
ii libx11-xcb1 2:1.6.7-1
ii libxcb-shm0 1.13.1-2
ii libxcb1 1.13.1-2
ii libxext6 2:1.3.3-1+b2
ii libxrender1 1:0.9.10-1
ii libxt6 1:1.1.5-1+b3
ii psmisc 23.2-1
ii x11-utils 7.7+4
ii zlib1g 1:1.2.11.dfsg-1
Versions of packages thunderbird recommends:
ii hunspell-en-ca [hunspell-dictionary] 1:2018.04.16-1
ii hunspell-en-gb [hunspell-dictionary] 1:6.2.0-1
ii hunspell-en-us [hunspell-dictionary] 1:2018.04.16-1
ii hunspell-en-za [hunspell-dictionary] 1:6.2.0-1
ii lightning 1:68.4.1-1~deb10u1
ii myspell-en-au [myspell-dictionary] 2.1-5.4
Versions of packages thunderbird suggests:
ii apparmor 2.13.2-10
ii fonts-lyx 2.3.2-1
ii libgssapi-krb5-2 1.17-3
-- no debconf information
--- End Message ---
