Skip to content

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

New issue
New issue
Closed
Closed
"Unable to load the desired message" after update to 0.7.5#643
Labels
0. to triagebugneeds info

Description

@Sp1l
Sp1l
opened on Nov 28, 2017

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:

Details { "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)
Details ``` {"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)
Details ``` File not found (not in directory where nextcloud.log is nor in nextcloudroot/data ```
Horde SMTP log (data/horde_smtp.log)
Details ``` File not found (not in directory where nextcloud.log is nor in nextcloudroot/data ```
Browser log
Details ``` 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>

Activity

  1. ChristophWurst commented on Nov 28, 2017

    @ChristophWurst
    ChristophWurst
    on Nov 28, 2017
    Member

    pool not functional, requires restart of the pool

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

  2. ChristophWurst
    added
    0. to triage
    bug
    on Nov 28, 2017
  3. ChristophWurst
    added this to the milestone on Nov 28, 2017

  4. Sp1l commented on Nov 28, 2017

    @Sp1l
    Sp1l
    on Nov 28, 2017
    Author

    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

  5. ChristophWurst commented on Nov 28, 2017

    @ChristophWurst
    ChristophWurst
    on Nov 28, 2017
    Member

    Operating system: FreeBSD 11.1p1 amd64

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

  6. Sp1l commented on Nov 28, 2017

    @Sp1l
    Sp1l
    on Nov 28, 2017
    Author

    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.

  7. ChristophWurst commented on Nov 28, 2017

    @ChristophWurst
    ChristophWurst
    on Nov 28, 2017
    Member

    Did you enable debug mode via config.php?

  8. Sp1l commented on Nov 28, 2017

    @Sp1l
    Sp1l
    on Nov 28, 2017
    Author

    Yes, loglevel is set to 0

    'loglevel' => 0,

  9. ChristophWurst commented on Nov 28, 2017

    @ChristophWurst
    ChristophWurst
    on Nov 28, 2017
    Member

    No, I mean
    "debug" => true 😉

  10. ChristophWurst commented on Nov 28, 2017

    @ChristophWurst
    ChristophWurst
    on Nov 28, 2017
    Member

    mail/lib/Account.php

    Line 147 in fad0eb6

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

  11. Sp1l commented on Nov 28, 2017

    @Sp1l
    Sp1l
    on Nov 28, 2017
    Author

    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.

  12. ChristophWurst commented on Dec 12, 2017

    @ChristophWurst
    ChristophWurst
    on Dec 12, 2017
    Member

    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.

  13. ChristophWurst
    added
    help wanted
    on Dec 12, 2017
  14. ChristophWurst
    removed this from the 0.7.6 milestone on Dec 12, 2017

  15. Sp1l commented on Dec 12, 2017

    @Sp1l
    Sp1l
    on Dec 12, 2017
    Author

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

  16. ChristophWurst commented on Dec 12, 2017

    @ChristophWurst
    ChristophWurst
    on Dec 12, 2017
    Member

    Any timeline for 13.0.0beta2?

    Soon nextcloud/server#7425 😉

  17. Sp1l commented on Dec 12, 2017

    @Sp1l
    Sp1l
    on Dec 12, 2017
    Author

    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

  18. Sp1l commented on Jan 23, 2018

    @Sp1l
    Sp1l
    on Jan 23, 2018
    Author

    Updated the FreeBSD port to 0.7.9
    Running Nextcloud 13.0.0-RC1

    Problem persists (still running via fpm)

  19. Sp1l commented on Jan 26, 2018

    @Sp1l
    Sp1l
    on Jan 26, 2018
    Author

    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

  20. ChristophWurst commented on Jan 26, 2018

    @ChristophWurst
    ChristophWurst
    on Jan 26, 2018
    Member

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

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

  21. ChristophWurst commented on Jan 26, 2018

    @ChristophWurst
    ChristophWurst
    on Jan 26, 2018
    Member

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

  22. ChristophWurst commented on Mar 28, 2018

    @ChristophWurst
    ChristophWurst
    on Mar 28, 2018
    Member

    Can this issue be closed?

  23. ChristophWurst
    added
    needs info
    and removed
    help wanted
    on Mar 28, 2018

  24. Sp1l commented on Jul 7, 2018

    @Sp1l
    Sp1l
    on Jul 7, 2018
    Author

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

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

  25. ChristophWurst commented on Jul 23, 2018

    @ChristophWurst
    ChristophWurst
    on Jul 23, 2018
    Member

    Thanks for your feedback 😃

  26. ChristophWurst
    closed this as completedon Jul 23, 2018

  27. lock commented on Nov 20, 2018

    @lock
    lockBot
    on Nov 20, 2018

    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.

  28. lock
    locked and limited conversation to collaborators on Nov 20, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    0. to triagebugneeds info

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions