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/config-v1.1.xml?emailaddress=foobar@probier.email <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 someaddress@probier.email. *** 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
