"Unable to load the desired message" after update to 0.7.5

[Sp1l]

Steps to reproduce

1. Install mail 0.7.4
2. Update Nextcloud from 12.0.3 to 13.0.0.6
3. Update mail to 0.7.5

Expected behaviour

Display message content

Actual behaviour

"Unable to load the desired message :-/" is displayed in the message frame.
PHP-FPM log shows

WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning 8 children, there are 0 idle, and 6 total children
pool not functional, requires restart of the pool

Mail app

Mail app version: 0.7.9

Mailserver or service: Dovecot 2.2.33.2

Transport security - IMAP: None

Transport security - SMTP: smtps (465)

Number of accounts: 10

Mail app version build date: (only if you are using a Nightly Build)

Server configuration

Operating system: FreeBSD 11.1p1 amd64

Web server: Apache 2.4.29

Database: MariaDB 10.2

PHP version: 7.1.12 FPM

Version: (see admin page) Nextcloud 13.0.0 RC3

Updated from an older version or fresh install: 12.0.3, 13.0.0b1, 13.0.0b3, 13.0.0rc1

List of activated apps:
Enabled:

• activity: 2.6.1
• admin_audit: 1.3.0
• bookmarks: 0.10.1
• calendar: 1.5.6
• comments: 1.3.0
• contacts: 2.0.1
• dav: 1.4.5
• federatedfilesharing: 1.3.1
• federation: 1.3.0
• files: 1.8.0
• files_pdfviewer: 1.2.0
• files_sharing: 1.5.0
• files_texteditor: 2.5.1
• files_trashbin: 1.3.0
• files_versions: 1.6.0
• files_videoplayer: 1.2.0
• firstrunwizard: 2.2.1
• gallery: 18.0.0
• logreader: 2.0.0
• lookup_server_connector: 1.1.0
• mail: 0.7.5
• nextcloud_announcements: 1.2.0
• notes: 2.3.1
• notifications: 2.1.0
• oauth2: 1.1.0
• passman: 2.1.4
• password_policy: 1.3.0
• provisioning_api: 1.3.0
• serverinfo: 1.3.0
• sharebymail: 1.3.0
• survey_client: 1.1.0
• systemtags: 1.3.0
• theming: 1.4.1
• twofactor_backupcodes: 1.2.3
• twofactor_totp: 1.3.1
• twofactor_u2f: 1.4.0
• updatenotification: 1.3.0
• user_external: 0.4
• workflowengine: 1.3.0
  Disabled:
• encryption
• files_external
• user_ldap

The content of config/config.php:

{ "system": { "appstoreenabled": false, "appstoreurl": "https:\/\/api.owncloud.com\/v1", "instanceid": "***REMOVED SENSITIVE VALUE***", "passwordsalt": "***REMOVED SENSITIVE VALUE***", "datadirectory": "***REMOVED SENSITIVE VALUE***", "dbtype": "mysql", "version": "13.0.0.6", "installed": true, "theme": "", "trusted_domains": [ "nc.example.org", "cloud.example.net" ], "dbname": "***REMOVED SENSITIVE VALUE***", "dbhost": "***REMOVED SENSITIVE VALUE***", "dbtableprefix": "oc_", "dbuser": "***REMOVED SENSITIVE VALUE***", "dbpassword": "***REMOVED SENSITIVE VALUE***", "forcessl": true, "ldapIgnoreNamingRules": false, "loglevel": 0, "logfile": "\/var\/log\/nextcloud.log", "user_backends": [ { "class": "OC_User_IMAP", "arguments": [ "{imap.example.net:144\/imap}" ] } ], "secret": "***REMOVED SENSITIVE VALUE***", "trashbin_retention_obligation": "auto", "htaccess.RewriteBase": "\/", "mail_smtpmode": "smtp", "mail_from_address": "***REMOVED SENSITIVE VALUE***", "mail_domain": "***REMOVED SENSITIVE VALUE***", "mail_smtpsecure": "tls", "mail_smtphost": "***REMOVED SENSITIVE VALUE***", "mail_smtpport": "587", "mail_smtpauth": 1, "mail_smtpname": "***REMOVED SENSITIVE VALUE***", "mail_smtppassword": "***REMOVED SENSITIVE VALUE***", "appstore.experimental.enabled": false, "overwrite.cli.url": "https:\/\/nc.example.org", "maintenance": false, "app.mail.accounts.default": { "email": "%USERID%", "imapHost": "imap.example.net", "imapPort": 144, "smtpHost": "smtp.example.net", "smtpPort": 486, "smtpSslMode": "tls" } } } ```

Client configuration

Browser: Firefox 57.0, Chrome 62.0.3202.94

Operating system: Win 10 Pro 1709

Logs

Web server error log

[Fri Nov 17 09:00:07.825110 2017] [mpm_event:notice] [pid 86068:tid 34389188608] AH00491: caught SIGTERM, shutting down
[Fri Nov 17 09:17:48.661439 2017] [http2:info] [pid 16872:tid 34389188608] AH03090: mod_http2 (v1.10.13-git, feats=CHPRIO+SHA256+INVHD+DWINS, nghttp2 1.27.0), initializing...
[Fri Nov 17 09:17:48.663609 2017] [mpm_event:notice] [pid 16872:tid 34389188608] AH00489: Apache/2.4.29 (FreeBSD) LibreSSL/2.6.3 configured -- resuming normal operations
[Fri Nov 17 09:17:48.663699 2017] [core:notice] [pid 16872:tid 34389188608] AH00094: Command line: '/usr/local/sbin/httpd -D NOHTTPACCEPT'

[27-Nov-2017 21:59:20] NOTICE: configuration file /usr/local/etc/php-fpm.conf test is successful
[27-Nov-2017 21:59:20] NOTICE: fpm is running, pid 35511
[27-Nov-2017 21:59:20] NOTICE: ready to handle connections
[27-Nov-2017 21:59:30] WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning 8 children, there are 0 idle, and 5 total children
[27-Nov-2017 21:59:31] WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning 16 children, there are 0 idle, and 6 total children
[27-Nov-2017 21:59:32] WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning 32 children, there are 0 idle, and 7 total children
[27-Nov-2017 21:59:42] WARNING: [pool www] server reached pm.max_children setting (8), consider raising it
[28-Nov-2017 19:20:30] WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning 8 children, there are 0 idle, and 6 total children
[28-Nov-2017 19:22:52] WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning 8 children, there are 0 idle, and 6 total children
[28-Nov-2017 19:23:30] WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning 8 children, there are 0 idle, and 6 total children
[28-Nov-2017 19:23:31] WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning 16 children, there are 0 idle, and 7 total children
[28-Nov-2017 19:23:32] WARNING: [pool www] server reached pm.max_children setting (8), consider raising it
[28-Nov-2017 19:29:54] WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning 8 children, there are 0 idle, and 6 total children
[28-Nov-2017 19:30:51] WARNING: [pool www] server reached pm.max_children setting (8), consider raising it
[28-Nov-2017 19:37:49] WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning 8 children, there are 0 idle, and 6 total children
[28-Nov-2017 19:51:48] WARNING: [pool www] server reached pm.max_children setting (8), consider raising it

Server log (data/nextcloud.log)

``` {"reqId":"gCqrETpJKQ3rWeTWqvMs","level":0,"time":"2017-11-28T18:23:22+00:00","remoteAddr":"172.17.2.169","user":"testuser","app":"mail","method":"GET","url":"\/index.php\/apps\/mail\/","message":"default config to create a default account found","userAgent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"13.0.0.6"} {"reqId":"gCqrETpJKQ3rWeTWqvMs","level":1,"time":"2017-11-28T18:23:22+00:00","remoteAddr":"172.17.2.169","user":"testuser","app":"mail","method":"GET","url":"\/index.php\/apps\/mail\/","message":"building default account for user testuser","userAgent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"13.0.0.6"} {"reqId":"gCqrETpJKQ3rWeTWqvMs","level":3,"time":"2017-11-28T18:23:22+00:00","remoteAddr":"172.17.2.169","user":"testuser","app":"PHP","method":"GET","url":"\/index.php\/apps\/mail\/","message":"Undefined index: imapSslMode at \/usr\/local\/www\/nextcloud\/apps\/mail\/lib\/Service\/DefaultAccount\/Config.php#73","userAgent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"13.0.0.6"} {"reqId":"RVMRdWQQriW7g0QRSgEh","level":0,"time":"2017-11-28T18:23:25+00:00","remoteAddr":"172.17.2.169","user":"testuser","app":"mail","method":"GET","url":"\/index.php\/apps\/mail\/api\/accounts\/-2\/folders","message":"default config to create a default account found","userAgent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"13.0.0.6"} {"reqId":"RVMRdWQQriW7g0QRSgEh","level":1,"time":"2017-11-28T18:23:25+00:00","remoteAddr":"172.17.2.169","user":"testuser","app":"mail","method":"GET","url":"\/index.php\/apps\/mail\/api\/accounts\/-2\/folders","message":"building default account for user testuser","userAgent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"13.0.0.6"} {"reqId":"RVMRdWQQriW7g0QRSgEh","level":3,"time":"2017-11-28T18:23:25+00:00","remoteAddr":"172.17.2.169","user":"testuser","app":"PHP","method":"GET","url":"\/index.php\/apps\/mail\/api\/accounts\/-2\/folders","message":"Undefined index: imapSslMode at \/usr\/local\/www\/nextcloud\/apps\/mail\/lib\/Service\/DefaultAccount\/Config.php#73","userAgent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"13.0.0.6"} {"reqId":"4FdvJemidpUlS5Dja5G8","level":0,"time":"2017-11-28T18:23:26+00:00","remoteAddr":"172.17.2.169","user":"testuser","app":"mail","method":"GET","url":"\/index.php\/apps\/mail\/api\/accounts\/-2\/folders\/5USCT1g%3D\/messages?filter=","message":"default config to create a default account found","userAgent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"13.0.0.6"} {"reqId":"4FdvJemidpUlS5Dja5G8","level":1,"time":"2017-11-28T18:23:26+00:00","remoteAddr":"172.17.2.169","user":"testuser","app":"mail","method":"GET","url":"\/index.php\/apps\/mail\/api\/accounts\/-2\/folders\/5USCT1g%3D\/messages?filter=","message":"building default account for user testuser","userAgent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"13.0.0.6"} {"reqId":"4FdvJemidpUlS5Dja5G8","level":3,"time":"2017-11-28T18:23:26+00:00","remoteAddr":"172.17.2.169","user":"testuser","app":"PHP","method":"GET","url":"\/index.php\/apps\/mail\/api\/accounts\/-2\/folders\/5USCT1g%3D\/messages?filter=","message":"Undefined index: imapSslMode at \/usr\/local\/www\/nextcloud\/apps\/mail\/lib\/Service\/DefaultAccount\/Config.php#73","userAgent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"13.0.0.6"} {"reqId":"4FdvJemidpUlS5Dja5G8","level":0,"time":"2017-11-28T18:23:26+00:00","remoteAddr":"172.17.2.169","user":"testuser","app":"mail","method":"GET","url":"\/index.php\/apps\/mail\/api\/accounts\/-2\/folders\/5USCT1g%3D\/messages?filter=","message":"loading messages of folder <5USCT1g=>","userAgent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"13.0.0.6"} ```

Horde IMAP log (data/horde_imap.log)

``` File not found (not in directory where nextcloud.log is nor in nextcloudroot/data ```

Horde SMTP log (data/horde_smtp.log)

``` File not found (not in directory where nextcloud.log is nor in nextcloudroot/data ```

Browser log

``` Insert your browser log here, this could for example include:

a) The javascript console log
b) The network log
c) ...

</details>


<bountysource-plugin>

---
Want to back this issue? **[Post a bounty on it!](https://www.bountysource.com/issues/52069025-unable-to-load-the-desired-message-after-update-to-0-7-5?utm_campaign=plugin&utm_content=tracker%2F44154351&utm_medium=issues&utm_source=github)** We accept bounties via [Bountysource](https://www.bountysource.com/?utm_campaign=plugin&utm_content=tracker%2F44154351&utm_medium=issues&utm_source=github).
</bountysource-plugin>

[ChristophWurst]

pool not functional, requires restart of the pool

I'm not a php-fpm expert, but this looks suspicious.

[Sp1l]

pool not functional, requires restart of the pool

That happens after (because of?) opening a message. PHP-FPM runs fine until I enable the mail app and open it, that's when these pool not functional errors appear

[ChristophWurst]

Operating system: FreeBSD 11.1p1 amd64

Btw, I don't think we support anything other than Linux 😞

[Sp1l]

Don't really need to generally, it's just another platform to run PHP on 😄

Any clue where I should find the logfiles? https://github.com/nextcloud/mail/blob/master/lib/Account.php#L148 shows that they should appear in <datadirectory> but I haven't found the logfiles there. Permissions on the directory show that apache can write there.

[ChristophWurst]

Did you enable debug mode via config.php?

[Sp1l]

Yes, loglevel is set to 0

'loglevel' => 0,

[ChristophWurst]

No, I mean
"debug" => true 😉

[ChristophWurst]

mail/lib/Account.php

Line 147 in fad0eb6

if ($this->config->getSystemValue('debug', false)) {

😉

[Sp1l]

Oeps! Hadn't found that one. Now enabled and I have the logs. No apparent errors in the IMAP log

S: 5 OK Fetch completed (0.004 + 0.000 + 0.003 secs).
>> Command 5 took 0.2285 seconds.
C: 6 LOGOUT
S: * OK [CLOSED] Previous mailbox closed.
S: * BYE LOGOUT received
S: 6 OK Completed
>> Command 6 took 0.0015 seconds.

[ChristophWurst]

Unassigning this from the current release milestone as I don't know what's going on here. Could be the unsupported platform, a misconfiguration of php-fpm or a bug in the app. I can't tell.

[Sp1l]

Just verified that the issue is still there in 0.7.6.
Any timeline for 13.0.0beta2?

[ChristophWurst]

Any timeline for 13.0.0beta2?

Soon nextcloud/server#7425 😉

[Sp1l]

Saw the notification too late 😄
Just tested with 13.0.0beta2, error still the same.
FreeBSD port for nextcloud-mail updated
Nextcloud 13 is still only a PR

[Sp1l]

Updated the FreeBSD port to 0.7.9
Running Nextcloud 13.0.0-RC1

Problem persists (still running via fpm)

[Sp1l]

Problem persists in 13.0.0-RC3 with Mail 0.7.9.
Found some entries in the Nextcoud logs:

Error | PHP | Undefined index: imapSslMode at /usr/local/www/nextcloud/apps/mail/lib/Service/DefaultAccount/Config.php#73 | 2018-01-26T21:52:06+0100
-- | -- | -- | --
Error | PHP | Undefined index: imapSslMode at /usr/local/www/nextcloud/apps/mail/lib/Service/DefaultAccount/Config.php#73 | 2018-01-26T21:52:05+0100
Error | PHP | Undefined index: imapSslMode at /usr/local/www/nextcloud/apps/mail/lib/Service/DefaultAccount/Config.php#73 | 2018-01-26T21:52:04+0100

[ChristophWurst]

/usr/local/www/nextcloud/apps/mail/lib/Service/DefaultAccount/Config.php

Oh, you're using a default account. I overlooked that.

[ChristophWurst]

As a start, please see the admin docs for a minimal configuration:
https://github.com/nextcloud/mail/blob/ecf34360a7d14f0593deb4033714c1b894d3c778/doc/admin.md#minimal-configuration

[ChristophWurst]

Can this issue be closed?

[Sp1l]

Late response... Just updated to 0.8.2 and all seems well now.

Already closed and that's a good thing. Thanks Christoph!

[ChristophWurst]

Thanks for your feedback 😃

[lock]

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs and questions.