Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Mail App Unexpected error during account creation #2971

Closed
nestorf5 opened this issue Apr 22, 2020 · 34 comments
Closed

Mail App Unexpected error during account creation #2971

nestorf5 opened this issue Apr 22, 2020 · 34 comments

Comments

@nestorf5
Copy link

nestorf5 commented Apr 22, 2020

Expected behavior

Open email account

Actual behavior

Cannot connect

Mail app

Mail app version: (see apps admin page, e.g. 0.5.3)

Mailserver or service: (e.g. Outlook, Yahoo, Gmail, Exchange,...)

Server configuration

Operating system: Debian 9

Web server: Apache

Database: MariaDB

PHP version: 7.4

Nextcloud Version: 18.0.3

Client configuration

Browser: chrome, edge, firefox

Operating system: W10

@nestorf5
Copy link
Author

No matter what user and/or email account , always says: Unexpected error during account creation.
Tried imap and smtp with and without security (tls, ssl, none)

Operating system: Debian 9
Web server: Apache
Database: MariaDB
PHP version: 7.4.4
Nextcloud Version: 18.0.3

Client:
Same thing with Windows and debian running different browser

@ChristophWurst
Copy link
Member

Expected behavior

Tell us what should happen

Actual behavior

Tell us what happens instead

Mail app

Mail app version: (see apps admin page, e.g. 0.5.3)

Mailserver or service: (e.g. Outlook, Yahoo, Gmail, Exchange,...)

Server configuration

Operating system: (e.g. Debian 8)

Web server: (e.g. Apache, Nginx,...)

Database: (e.g. MariaDB, SQLite or PostgreSQL)

PHP version: (e.g. 7.0)

Nextcloud Version: (see admin page, e.g. 13.0.2)

Client configuration

Browser: (e.g. Firefox 48)

Operating system: (e.g. Arch Linux)

The idea of this bug template is to use it 😉

The Nextcloud mail app offers an extensive logging system to make it easier identifying and tracking down bugs. Please enable debug mode and set the log level to debug in your admin settings. Then, try to reproduce your issue and take another look at data/nextcloud.log, data/horde_imap.log and data/horde_smtp.log.

@jficz

This comment has been minimized.

@nestorf5
Copy link
Author

Try imap with plain no tls auth and same thing. Just once,(uninstalling and reinstalling app) I could enter to gmail. So, I removed connection and retried, but no luck again.

@ChristophWurst
Copy link
Member

Could not open secure TLS connection to the IMAP server.

See https://github.com/nextcloud/mail/releases/tag/v1.1.4

@jficz
Copy link

jficz commented Apr 24, 2020

How exactly is my previous comment 'off-topic'?

btw, logs don't yield anything useful:

nextcloud.log:

{
  "reqId": ...,
  "level": 4,
  "time": "2020-04-24T09:08:03+00:00",
  "remoteAddr": ...,
  "user": ...,
  "app": "mail",
  "method": "POST",
  "url": "/apps/mail/api/accounts",
  "message": "Creating account failed: Could not connect to IMAP: Could not open secure TLS connection to the IMAP server.",
  "userAgent": "Mozilla/5.0 (X11; Linux x86_64; rv:75.0) Gecko/20100101 Firefox/75.0",
  "version": "18.0.4.2"
}
horde_imap.log
------------------------------
>> Fri, 24 Apr 2020 09:08:03 +0000
>> Connection to: imap://.../
>> Server connection took 0.0188 seconds.
S: * OK [CAPABILITY IMAP4rev1 SASL-IR LOGIN-REFERRALS ID ENABLE IDLE LITERAL+ STARTTLS LOGINDISABLED] Dovecot ready.
C: 1 STARTTLS
S: 1 OK Begin TLS negotiation now.
>> Command 1 took 0.0004 seconds.

Mail app v1.3.3
nginx version: nginx/1.14.2
PHP 7.3.14-1~deb10u1
mysqld Ver 5.7.29-32 for debian-linux-gnu on x86_64 (Percona Server (GPL), Release '32', Revision '56bce88')

@ChristophWurst
Copy link
Member

Because you hijack a unrelated report. In your case it's crystal clear what the issue is: your TLS connection fails. That is not the case with OP.

Could not connect to IMAP: Could not open secure TLS connection to the IMAP server.

Once again see https://github.com/nextcloud/mail/releases/tag/v1.1.4. This is easily fixable for self-hosted (or wrongly configured) mail servers.

@jficz
Copy link

jficz commented Apr 24, 2020

Because you hijack a unrelated report. In your case it's crystal clear what the issue is: your TLS connection fails. That is not the case with OP.

Not the case here. If anything I pointed out what the root cause might be. The OP is only citing what the App says, not what the logs say.

The app indeed says "Unexpected error during account creation." How do you think I landed on this report in the first place?

I take a little offense in you pointing out the same thing twice while expecting me to ignore it. My server is configured correctly, which is somewhat implied in my first comment - now I'm just stating it explicitly.

@ChristophWurst
Copy link
Member

I did not mean to offend.

Believe it or not, but so many people ignore my comments containing solutions if you don't point them to it a few times.

In your case it is definitely a TLS issue. For OP it could be the same, but it could be anything else as well. "Unexpected error during account creation." is the generic part that is always shown/logged. What matters are the details after.

My server is configured correctly

Can you connect to it with openssl on the CLI?

@jficz
Copy link

jficz commented Apr 24, 2020

I can connect to my server with various clients and I ran ssltest from the host where Mail app is connecting from. Everything checks out.

I think it's not TLS related as the problem prevails in the same manner the OP's does - no matter the (non)security settings, the app just won't connect. The only thing that changes is the error message in the log which just says "Creating account failed: Could not connect to IMAP: Error connecting to mail server." instead. Nothing specific in debug logs except stuff like "I'm going to try to connect to IMAP now".

I'll see if I can pull some useful logs from the IMAP server but I wouldn't count on it. I've tried to convince Dovecot to log IMAP session when I was debugging a different issue with user_external app but I never got more verbose than "establishing connection -> connection failed".

@ChristophWurst
Copy link
Member

But can you see the established connection on the IMAP server when Mail tries to connect?

@jficz
Copy link

jficz commented Apr 24, 2020

edit: only TLS is affected, plaintext login (on port 143) works when enabled on the server side, which no sanely configured server has. Login attempt to a properly configured server on port 143 without STARTTLS yields Could not connect to IMAP: No supported IMAP authentication method could be found. message in Nextcloud log but produces the same generic message in the Mail UI.

Nope, it appears the app doesn't even try to connect beyond initializing the IMAP session, regardless TLS settings:

Apr 24 17:04:21 mx dovecot: imap-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=... lip=..., TLS, TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)

@Anarch157a
Copy link

Apr 24 17:04:21 mx dovecot: imap-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=... lip=..., TLS, TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)

I can confirm what @cptMikky said. Here's my Mailcow Dovecot log:

Apr 24 18:55:28 mx dovecot: imap-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=<snip>, lip=<snip>, TLS handshaking: SSL_accept() failed: error:14094418:SSL routines:ssl3_read_bytes:tlsv1 alert unknown ca: SSL alert number 48

Doesn't matter if IMAP Security is 'none', 'SSL/TLS' or 'STARTTLS', the message on Dovecot's log is the same.

Mail App

  • Mail app version: 1.3.3
  • Mailserver or service: Mailcow Dovecot (self hosted)

Server configuration

  • Operating system: Debian Unstable
  • Web server: Nginx
  • Database: MariaDB
  • PHP version: 7.3
  • Nextcloud Version: 18.0.0

Client configuration

Browser: Firefox 75.0
Operating system: Linux (Debian Unstable)

@filipiff
Copy link

Maybe can be related. I had the same error "Unexpected error during account creation" and the following entries where logged in the log files.

dovecot log:
Apr 24 21:50:42 mail dovecot: imap-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=10.16.0.8, lip=10.16.0.4, TLS, session=<+9Msrg6kcqUKEAAI>

nextcloud log:
cloudix | 172.16.0.3 - - [24/Apr/2020:21:50:41 +0200] "POST /index.php/apps/mail/api/accounts HTTP/1.1" 400 925 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/80.0.3987.16 3 Safari/537.36"

Applying the config changes to the file apps.config.php referenced by @ChristophWurst did solved the problem. See:

Once again see https://github.com/nextcloud/mail/releases/tag/v1.1.4. This is easily fixable for self-hosted (or wrongly configured) mail servers.

Nextcloud 18.0.4.2
Mail 1.3.3

@jficz
Copy link

jficz commented Apr 24, 2020

I've tried disabling peer verification, too. It works, which leads me to believe that there's probably something wrong with the verification itself. I'll dig deeper.

@jficz
Copy link

jficz commented Apr 24, 2020

Ok, I'm confused now: changed the settings back to peer-verify=true and everything seems to be working just fine. Is there some kind of cache or something, that could affect the settings?

I only did one thing: apt upgrade, which did a miniscule update of openssl and libssl.

"Miniscule" as in a couple of downstream patches, not even increasing the package version. I'm going through the diffs now to see if there's something that might be related.

@nestorf5: what's your openssl and libssl package version? Mine are

openssl    1.1.1d-0+deb10u3
libssl1.1  1.1.1d-0+deb10u3

upgraded from deb10u2

@dengste
Copy link

dengste commented Apr 25, 2020

A little info: I struggled with the exact same problem. Reason was that I simply put in 'localhost' for the IMAP and SMTP server since they run on the same machine. However, it seems this always fails TLS verification. When entering the DNS name of the server, everything ran fine. This is a bit unfortunate, in my opinion.

@jficz
Copy link

jficz commented Apr 26, 2020

This is a bit unfortunate, in my opinion.

This is how SSL/TLS works in the first place. The server presents a certificate with a DNS name in it. The name presented in the cert must match the name the client used to resolve the server's address, hence the term verification.

As a rule of thumb, don't use localhost anywhere unless you have a really good reason to. If you think you have a good reason, you probably don't.

Also it doesn't make much sense to encrypt loopback traffic so try again with no encryption and see if the problem prevails.

@dengste
Copy link

dengste commented Apr 26, 2020

This is how SSL/TLS works in the first place.

I know. I admit it is naive to assume that 'localhost' would be exempt from TLS verification. What is needed though is an error message which clearly says that 'localhost' is missing from the certificate's CN. It's not even clear this is due to TLS verification at all. The Log only says "Creating account failed: Could not connect to IMAP: Error connecting to mail server."

it doesn't make much sense to encrypt loopback traffic

Of course not, but it is good practice to disable unencrypted connections completely, especially for SMTP.

try again with no encryption and see if the problem prevails

As I've written, I could fix this by using the external DNS names. Disabling TLS verification also works.

@ChristophWurst
Copy link
Member

What is needed though is an error message which clearly says that 'localhost' is missing from the certificate's CN. It's not even clear this is due to TLS verification at all. The Log only says "Creating account failed: Could not connect to IMAP: Error connecting to mail server."

Yes, ideally we should do that. We just have to check if Horde exposes this as we don't open the connection ourselves.

As far as I know php's openssl is used for the verification. So whichever cert chains this has access to your LE cert might be considered valid or not.

@jficz
Copy link

jficz commented Apr 27, 2020

As far as I know php's openssl is used for the verification. So whichever cert chains this has access to your LE cert might be considered valid or not.

Horde uses stream_socket_* to establish connections. Specifically, it uses stream_socket_enable_crypto to, well, enable crypto :)

This method should have access to whatever the system OpenSSL has access to. An error message can be extracted from there, too, but that would require patching the Horde Socket code.

@nestorf5
Copy link
Author

nestorf5 commented Apr 27, 2020 via email

@ChristophWurst
Copy link
Member

@cptMikky that is correct. Do you have specific changes in mind that we could send to Horde? They've integrated a few of our fixes. They might also accept small enhancements.

@jficz
Copy link

jficz commented Apr 28, 2020

Maybe we could leverage stream_notification_callback. I'm not exactly a developer but if I understand it correctly, this might be implemented entirely on the Mail app side.

Let me create a you-get-the-idea PR.

@ChristophWurst
Copy link
Member

Phew. That looks like this could either be very helpful or be pure PITA. The problem with the callback is that it breaks all the sequential control flow and I can't know which errors are already being handled by Horde as I assume they also do their specific tricks.

I have my doubts about the usefulness of this. It would be much more straight forward if the error is caught in Horde and get a dedicated error code or if we are able to derive this from the existing Horde error.

@jficz
Copy link

jficz commented Apr 28, 2020

Maybe I misunderstand the concept of callback but it looks to me like the callback is performed asynchronously and has no impact on the flow at all. It's just informative so the original idea was to only provide useful logs, not error handling.

@ChristophWurst
Copy link
Member

It's processed synchronous, like everything in php. But like you'd call a method on Horde and before that returns your callback runs somewhere else. There is no connection between these two paths. We'd need some global variable or similar to exchange the data.

@ChristophWurst
Copy link
Member

The flow I would like to see is that I call a Horde method and it just throws an exception with the details that I can use to react accordingly. Hope that makes sense.

@jficz
Copy link

jficz commented Apr 28, 2020

Just so that we are on the same page: I'm only trying to solve error reporting here, not error handling so from my perspective no connection between a method call and a log isn't that big of an issue, especially when the log message is verbose enough for a human to figure out the connection in their head. Think of it as an "admin" perspective in contrast to the "dev" perspective which you have. An admin isn't interested in call stack, he's interested in logs which tell him what's wrong. And in most cases the problem will not be in the code anyway so the dev will likely not be bothered about the problem in the first place.

Switching back to "dev" perspective, exceptions would of course be ideal. But that would mean code and error-handling paradigm changes in multiple Horde libraries.

Callback is the only way I can think of that would not require Horde-side changes.

On the other hand, for starters, we could update Horde lib functions to return the actual error code instead of just true/false. It's better than nothing but we'll still not have the actual upstream error message, just the general error code. Getting the message would require rewriting the methods' definitions and/or making them return a touple [int, string] instead of a single value. And that looks like an antipattern to me, not to mention breaking everything that uses those libs.

@ChristophWurst
Copy link
Member

Got it. Yet I think that the reported errors aren't that bad. What we really lack is good transportation of common error cases the user, as written in #3006. The specific reason of a TLS error is secondary.

@jficz
Copy link

jficz commented Apr 28, 2020

Do you differentiate between user and admin for the purpose of this discussion?

I agree that the user should be given an error message that is specific enough for them to have an idea of what's going on (as in #3006). The admin, on the other hand, should have the option to debug the issue, which requires specifics in log messages. Such messages should be in a debug log, not in the UI, because users don't care about them.

Like in my case, I still have no idea what was wrong and I'm not happy that it started working "on its own". That almost always means it's gonna come back to bite me in my behind exactly when I'll expect it the least :)

@ChristophWurst
Copy link
Member

It's not black and white. Like if there is an organization that uses Nextcloud and the users can't connect to their mail server then the admin will want to have a look. But if you have a personal instance of Nextcloud hosted somewhere and can't add your gmail account or similar then you'd like to know what is going on without having to get in contact with the support system of the hoster.

In any case, I do see your point. But this callback thing is very suspicious to me and I'm the one who has to maintain this code, so I'm very hesitant to blindly add this to our code base.

@jficz
Copy link

jficz commented Apr 28, 2020

I get your point, too. And in no case I want to force anything on you - the callback is just another crazy idea you may or may not consider. I certainly wouldn't mind if you drop it :)

Also:

But if you have a personal instance of Nextcloud hosted somewhere and can't add your gmail account or similar then you'd like to know what is going on without having to get in contact with the support system of the hoster.

That's not necessarily implied, it mostly depends on how the hosting works. As long as you can enable debug, you should be able to access the logs on your own. And if you can't enable it, you're most likely in no position to fix the problem without support anyway.

Let's close this one in favor of #3006 and let it sit for a few days. Maybe someone comes up with a better idea.

@stale
Copy link

stale bot commented Oct 31, 2020

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

@stale stale bot added the stale label Oct 31, 2020
@stale stale bot closed this as completed Dec 19, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

6 participants