nextcloud / mail

💌 Mail app for Nextcloud
https://apps.nextcloud.com/apps/mail
GNU Affero General Public License v3.0
850 stars 262 forks source link

Mail accounts created via provisioning do not work; "Invalid microsoft_oauth_client_id data provided to provideInitialState by mail" and "Invalid google_oauth_client_id data provided to provideInitialState by mail" #9230

Closed nagmat84 closed 2 weeks ago

nagmat84 commented 10 months ago

Steps to reproduce

I am running Nextcloud 28.0.1 with Mail App 3.5.0 and try to provision mail accounts via ./settings/admin/groupware. On the same server I run Dovecot 2.3.20 with a "master" password to fake SSO.

  1. Go to ./settings/admin/groupware, fill out Mail App Provisioning Settings for IMAP and SMTP, but neither configure GMail nor Microsoft integration
  2. Save config and click "Provision all accounts" (verify that the number of created accounts is as expected)
  3. Open Mail App and try to do something, e.g. send a new mail
  4. See a success message, shortly followed by an error message

In the Nextcloud logs I see the following errors (always in pairs):

Level      Application          Message
--------------------------------------------------------------------------------------------------------------
Warning    no app in context    Invalid microsoft_oauth_client_id data provided to provideInitialState by mail
Warning    no app in context    Invalid google_oauth_client_id data provided to provideInitialState by mail 

In order to ensure that there in nothing wrong on the server-side (e.g. Dovecot), I enabled authentication debugging in Dovecot, i.e. I set auth_verbose = yes, auth_verbose_passwords = yes, auth_debug = yes and auth_debug_passwords = yes in Dovecot. I get the following logs in Dovecot

auth: Debug: client in: AUTH   1   PLAIN   service=imap   secured=tls   session=Z6ccAHMOYoAqA0AAAFoNmwAAAAAAAAAB   lip=2a03:4000:5a:d9b::1   rip=2a03:4000:5a:d9b::1   lport=993   rport=32866   local_name=server.mhnnet.de   resp=<auth data> (previous base64 data may contain sensitive data)
auth: Debug: static(<my-uid>@<my-domain.tld>,2a03:4000:5a:d9b::1,<Z6ccAHMOYoAqA0AAAFoNmwAAAAAAAAAB>): Performing passdb lookup
auth: Debug: static(<my-uid>@<my-domain.tld>,2a03:4000:5a:d9b::1,<Z6ccAHMOYoAqA0AAAFoNmwAAAAAAAAAB>): lookup
auth: Debug: static(<my-uid>@<my-domain.tld>,2a03:4000:5a:d9b::1,<Z6ccAHMOYoAqA0AAAFoNmwAAAAAAAAAB>): allow_nets: Matching for network local
auth: Debug: static(<my-uid>@<my-domain.tld>,2a03:4000:5a:d9b::1,<Z6ccAHMOYoAqA0AAAFoNmwAAAAAAAAAB>): allow_nets: Matching for network 127.0.0.1/32
auth: Debug: static(<my-uid>@<my-domain.tld>,2a03:4000:5a:d9b::1,<Z6ccAHMOYoAqA0AAAFoNmwAAAAAAAAAB>): allow_nets: Matching for network ::1/128
auth: Debug: static(<my-uid>@<my-domain.tld>,2a03:4000:5a:d9b::1,<Z6ccAHMOYoAqA0AAAFoNmwAAAAAAAAAB>): allow_nets: Matching for network 202.61.202.193/32
auth: Debug: static(<my-uid>@<my-domain.tld>,2a03:4000:5a:d9b::1,<Z6ccAHMOYoAqA0AAAFoNmwAAAAAAAAAB>): allow_nets: Matching for network 2a03:4000:5a:d9b::1/128
auth: Debug: static(<my-uid>@<my-domain.tld>,2a03:4000:5a:d9b::1,<Z6ccAHMOYoAqA0AAAFoNmwAAAAAAAAAB>): Finished passdb lookup
auth: Debug: auth(<my-uid>@<my-domain.tld>,2a03:4000:5a:d9b::1,<Z6ccAHMOYoAqA0AAAFoNmwAAAAAAAAAB>): Auth request finished
auth: Debug: client passdb out: OK   1   user=<my-uid>@<my-domain.tld>
auth: Debug: auth client connected (pid=35882)
auth: Debug: master in: REQUEST   1022099457   35865   1   54318cf23b0d10441a76049ff2ffc04d   session_pid=35883   request_auth_token
auth: Debug: ldap(<my-uid>@<my-domain.tld>,2a03:4000:5a:d9b::1,<Z6ccAHMOYoAqA0AAAFoNmwAAAAAAAAAB>): Performing userdb lookup
auth: Debug: ldap(<my-uid>@<my-domain.tld>,2a03:4000:5a:d9b::1,<Z6ccAHMOYoAqA0AAAFoNmwAAAAAAAAAB>): user search: base=dc=server,dc=mhnnet,dc=de scope=subtree filter=(&(objectClass=mailAccount)(mailAccount=<my-uid>@<my-domain.tld>)) fields=uid,uid
auth: Debug: ldap(<my-uid>@<my-domain.tld>,2a03:4000:5a:d9b::1,<Z6ccAHMOYoAqA0AAAFoNmwAAAAAAAAAB>): result: uid=<my-uid>; uid unused
auth: Debug: ldap(<my-uid>@<my-domain.tld>,2a03:4000:5a:d9b::1,<Z6ccAHMOYoAqA0AAAFoNmwAAAAAAAAAB>): Finished userdb lookup
auth: Debug: master userdb out: USER   1022099457   <my-uid>@<my-domain.tld>   uid=999   gid=999   home=/var/spool/mail/vmail/<my-domain.tld>/<my-uid>   auth_mech=PLAIN   auth_token=b392817930fef857a921831f417f9c4c297a2103
imap-login: Login: user=<<my-uid>@<my-domain.tld>>, method=PLAIN, rip=2a03:4000:5a:d9b::1, lip=2a03:4000:5a:d9b::1, mpid=35883, TLS, session=<Z6ccAHMOYoAqA0AAAFoNmwAAAAAAAAAB>
imap(<my-uid>@<my-domain.tld>)<35883><Z6ccAHMOYoAqA0AAAFoNmwAAAAAAAAAB>: Disconnected: Logged out in=296 out=1615 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0

From the perspective of Dovecot, everything looks fine: the authentication succeeds, but the client (i.e. the Nextcloud Mail App) immediately logs out again without actually doing anything. I also confirmed manually via openssl s_client ... that log in with the user name and master password works.

My best guess: It seems that the Mail App closes the connection again as it stumbles upon Microsoft and Gmail integration not being configured.

Expected behavior

Provisioned mail accounts should also work without Microsoft and Gmail integration being set.

Actual behavior

Seemingly, mail accounts which have been centrally provisioned do not work without Microsoft and Gmail integration being set, too.

Mail app version

3.5.0

Mailserver or service

Self-hosted Dovecot on same machine

Operating system

Gentoo Linux

PHP engine version

PHP 8.2

Web server

Apache (supported)

Database

None

Additional info

No response

ChristophWurst commented 10 months ago

Invalid google_oauth_client_id data provided to provideInitialState by mail

Locate the message in data/nextcloud.log. Post the full line (json). Redact any sensitive infos, if necessary. The log message will tell us the inner/previous exception. JSON encoding of the client_id must throw an exception.

nagmat84 commented 10 months ago

Here you go. To my surprise, the log entries are astonishingly short. It seems there is no real backtrace:

{
    "reqId": "iVIHVwP4rAM90iEeobLn",
    "level": 2,
    "time": "2024-01-07T18:05:17+00:00",
    "remoteAddr": "217.236.252.159",
    "user": "matthias.nagel",
    "app": "no app in context",
    "method": "GET",
    "url": "/settings/admin/groupware",
    "message": "Invalid microsoft_oauth_client_id data provided to provideInitialState by mail",
    "userAgent": "Mozilla/5.0 (X11; Linux x86_64; rv:120.0) Gecko/20100101 Firefox/120.0",
    "version": "28.0.1.1",
    "data": []
}
{
    "reqId": "xVmwZSDh9LmHNV8CL7UH",
    "level": 2,
    "time": "2024-01-07T18:05:41+00:00",
    "remoteAddr": "217.236.252.159",
    "user": "matthias.nagel",
    "app": "no app in context",
    "method": "GET",
    "url": "/settings/admin/groupware",
    "message": "Invalid google_oauth_client_id data provided to provideInitialState by mail",
    "userAgent": "Mozilla/5.0 (X11; Linux x86_64; rv:120.0) Gecko/20100101 Firefox/120.0",
    "version": "28.0.1.1",
    "data": []
}

However, these error messages do not seem to be generated by the login of the Mail App to the mail server, but to be generated by visiting the admin page (the URL /settings/admin/groupware indicates that). Definitely, these error messages shouldn't be there either and they indicate another problem, but they do not seem to be related to my original problem.

This leaves me totally clueless why the Mail App is able to successfully login to the mail server, logs out again immediately and then fails to do anything meaningful (i.e. sending an email, composing an email, moving emails between IMAP folders, etc.) without even logging any related error.

nagmat84 commented 10 months ago

After a lot of debugging, disabling TLS and packet sniffing I believe, I finally found out what the root issues are. It seems there are at least two unrelated bugs involved.

"If default folders are not configured, then the Mail App does nothing for most actions"

This does not even seem to be actually related to mail box provisioning, but mail box provisiong makes it much more likely to run into this problem.

If the default folders for "Sent Messages" and "Trash" are not configured, then sending a mail or deleting a mail, resp., does not work. If the default folders are not configured, but one attempts to perform the respective tasks, the Mail app first presents a success message to the user, shortly followed by an error message. Under the hood, the Mail app does connects to the IMAP server, logs in, does not do anything and logs out immediately. No error message is logged to the central log to indicate what the actual problem is (i.e. default folders being unconfigured). The error message presented to the user isn't helpful either.

In order to get the Mail app to work, the default folders must be set to point to actually existing folders like

Setting default folders

This issue also affects mail accounts which are set up manually, i.e. the problem is unrelated to mailbox provision. However, with mail provisioning the problem is more severe, because user who do not setup their own mail account expect their mail account to work out of the box and probably will never find these configuration options on their own unless they are explicitly told to set them.

The current workaround is to tell my user that they have to configure their default folders first, before they can properly use the Mail App.

IMHO, there are at least two things which should be solved here.

  1. Presenting a proper error message, which actually indicates what the underlying problem is. For example an error message like "Could not sent message, as folder for sent messages is not configured", "Could not delete message, as trash folder is not configured". Don't fail silently without providing a clue what is going on.
  2. Configure the default folders for automatically provisioned mail accounts. User with centrally managed mail accounts expect that the Mail app works out-of-the-box without manual configuration first. I see two options how this could be achieved:

    1. The admin page /settings/admin/groupware could provide additional fields which allow to set non-empty default values for the default folders. The default folders are set to those values during the provisioning step.
    2. Alternatively, if the default folders are not set (i.e. empty), the Mail app should auto-detect the corresponding folders as reported by the server. The IMAP standard provides a feature which allows the IMAP server to report which "special" folders exist and which folder is used for what. The IMAP server flags these special folders with the IMAP attributes \Drafts, \Junk, \Sent and \Trash (see RFC 6154.).

    In either of the above cases, users should still have the option to set the default folders to a different location of their liking, but the initial configuration should be a working one.

Sieve does not use the master password for login

If a master password is set and Sieve is enabled, the Sieve client does not use the master password. The Sieve client of the Mail app ignores that and does not authenticate. At least this is what I can observer on the server-side.

This conjecture is also backed up by the layout of the configuration page /settings/admin/groupware. The settings are ordered as "General", "IMAP", "SMTP", "Master password", "Sieve". It seems that the master password only controls "IMAP" and "SMTP", but is not relevant for "Sieve".

My current workaround is to disable Sieve support in the Mail App.

nextcloud-command commented 1 month ago

Hi there! It looks like this issue hasn’t seen much activity for a while and might need a bit more information to move forward. If we don’t hear back soon, we may close it to keep things organized. Thanks again for your contributions – we really appreciate it!