nextcloud / mail

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

Mail App doesn't open with faulty IMAP Server #3014

Closed akoyaxd closed 4 years ago

akoyaxd commented 4 years ago

Edit from 01.05.2020: Hydroxide (the IMAP Server) was causing the issue, not the mail App. See This answer

Expected behavior

I click the Mail App Icon in the Top Bar of Nextcloud and the App opens and shows my eMails

Actual behavior

The App doesn't open. It just loads and after 30 Seconds the reverse Proxy shows a 504 Gateway Time-out.

Mail app

Mail app version: Upgraded from 1.3.3 to 1.3.4

Mailserver or service: Protonmail (using hydroxide as IMAP and SMTP Server)

Server configuration

Operating system: Ubuntu 20.04

Web server: Apache (Nginx as reverse Proxy)

Database: MariaDB

PHP version: 7.4

Nextcloud Version: 18.0.4

Client configuration

Browser: Firefox 75

Operating system: Arch Linux

Logs

I can't see a App related Error Message. But I get a ton of the following Error Messages:

[PHP] Error: Trying to access array offset on value of type null at /var/www/nextcloud/3rdparty/leafo/scssphp/src/Compiler.php#5230 at 2020-04-28T06:58:17+00:00

ChristophWurst commented 4 years ago

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 and data/horde_imap.log.

ChristophWurst commented 4 years ago

Also, what was your previous version?

akoyaxd commented 4 years ago

I upgrades from 1.3.3

I enabled both, debugmode and the debug loglevel. The horde_imap.log wasn't altered since I upgraded to 3.3.4.

The logs are now full of Error logs like the following: RuntimeException: App class OCA\TwoFactorTOTP\AppInfo\Application is not setup via query() but directly But the mail App seems not occur in the logs.

ChristophWurst commented 4 years ago

The horde_imap.log wasn't altered since I upgraded to 3.3.4.

Then this might not have anything to do with IMAP. Is your database OK?

akoyaxd commented 4 years ago

How can I check that? Is it one of the following occ commands?

db:add-missing-indices Add missing indices to the database tables maintenance:mimetype:update-db Update database mimetypes and update filecache

ChristophWurst commented 4 years ago

Is your db running? Does it log any errors?

I can't help with the problem until you've found proof that this is an issue of this app's code. Check all the possible log files and read the manuals of your software stack. This is out of scope for me to debug.

akoyaxd commented 4 years ago

I see.. Well, since my Nextcloud is running fine, except for for the Mail app, I guess the DB works fine.

I will try get some log that refer to the Mail app.

ChristophWurst commented 4 years ago

I see.. Well, since my Nextcloud is running fine, except for for the Mail app, I guess the DB works fine.

I mean it's not rocket science to check a few logs, right?

Just let us know if you found anything useful.

akoyaxd commented 4 years ago

I looked into the mysql logs. But As far as I can tell, they look fine.

Logs from /var/log/mysql/error.log 2020-04-28 15:04:48 0 [Note] InnoDB: Using Linux native AIO 2020-04-28 15:04:48 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2020-04-28 15:04:48 0 [Note] InnoDB: Uses event mutexes 2020-04-28 15:04:48 0 [Note] InnoDB: Compressed tables use zlib 1.2.11 2020-04-28 15:04:48 0 [Note] InnoDB: Number of pools: 1 2020-04-28 15:04:48 0 [Note] InnoDB: Using SSE2 crc32 instructions 2020-04-28 15:04:48 0 [Note] InnoDB: Initializing buffer pool, total size = 1G, instances = 8, chunk size = 128M 2020-04-28 15:04:49 0 [Note] InnoDB: Completed initialization of buffer pool 2020-04-28 15:04:49 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority(). 2020-04-28 15:04:49 0 [Note] InnoDB: 128 out of 128 rollback segments are active. 2020-04-28 15:04:49 0 [Note] InnoDB: Creating shared tablespace for temporary tables 2020-04-28 15:04:49 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ... 2020-04-28 15:04:49 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB. 2020-04-28 15:04:49 0 [Note] InnoDB: Waiting for purge to start 2020-04-28 15:04:49 0 [Note] InnoDB: 10.3.22 started; log sequence number 2866875305; transaction id 473306 2020-04-28 15:04:49 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool 2020-04-28 15:04:49 0 [Note] Plugin 'FEEDBACK' is disabled. 2020-04-28 15:04:49 0 [Note] Server socket created on IP: '127.0.0.1'. 2020-04-28 15:04:49 0 [Note] Reading of all Master_info entries succeeded 2020-04-28 15:04:49 0 [Note] Added new Master_info '' to hash table 2020-04-28 15:04:49 0 [Note] /usr/sbin/mysqld: ready for connections. Version: '10.3.22-MariaDB-1ubuntu1' socket: '/run/mysqld/mysqld.sock' port: 3306 Ubuntu 20.04 2020-04-28 15:04:50 0 [Note] InnoDB: Buffer pool(s) load completed at 200428 15:04:50

akoyaxd commented 4 years ago

I also can confirm, that this seems to only affect only on (or al least not all) user. Is there a way to wipe settings for a user?

ChristophWurst commented 4 years ago

What you might also try is increase the timeout on the reverse proxy to check what happens after the 30s.

ChristophWurst commented 4 years ago

Like the request might now actually fail or throw an error but is slow for some other reason.

akoyaxd commented 4 years ago

What you might also try is increase the timeout on the reverse proxy to check what happens after the 30s.

Well, that's something I cloud have thought of myself.. I tried to open the Mail App while calling the Nextcloud websever (the apache2 server) directly. But I just loads endlessly (more than 2 hours).

But again, this seems only to affect one user. The logs show activity of the app from other users.

Some example logs. [mail] Debug: partial sync 12:Spam took 0s at 2020-04-29T07:15:19+00:00 [mail] Debug: partial sync 12:Spam took 0s at 2020-04-29T07:15:19+00:00 [mail] Debug: partial sync 12:Sent Messages - get vanished messages via Horde took 0s at 2020-04-29T07:15:19+00:00

akoyaxd commented 4 years ago

It seems, that hydroxide was causing the issue. It somehow didn't properly respond to the Mail App. After restarting hydroxide the Mail App now works again.

I'm sorry for not testing this earlier. Maybe there should be a timeout for such a situation, like when the imap server is faulty..

Otehrwise the Issue can be closed from my side.

ChristophWurst commented 4 years ago

There is a timeout for connections. But what you are referring to is more like an exponential back-off strategy when an account fails over and over. We don't have that, yet.