Mail: Can't fetch folders/mail from server (HTTP 500)

Created on 22 Oct 2016 · 9Comments · Source: nextcloud/mail

Steps to reproduce

Set up mail information (manual setup with own courier-IMAP server)
Connection successful, is added to side menu
Attempt to view mail

NOTE: I migrated from owncloud to nextcloud, thus the old folder names are kept!

Expected behaviour

Inbox folders load, mail is displayed (works e.g. with GMail)

Actual behaviour

Error message: "Fehler beim Laden des ausgewählten Kontos.", screen stays white, loading icon is spinning

JS error:

jquery.js:8630 GET http://XXX:8080/owncloud/index.php/apps/mail/accounts/4/folders 500 (Internal Server Error)

I assume everything except one of the IMAP commands work fine, but still triggers an internal server error, and thus nothing is displayed!

Mail app

Mail app version: Mail 0.6.0

Mailserver or service: Own Courier-IMAP server

Transport security - IMAP: SSL/TLS

Transport security - SMTP:SSL/TLS

Number of accounts: 1

Server configuration

Operating system: Debian 8

Web server: apache2

Database: MySQL/MariaDB

PHP version:

Version: 9.1.1

Enabled:
  - activity: 2.3.2
  - calendar: 1.4.0
  - comments: 0.3.0
  - contacts: 1.4.0.0
  - dav: 0.2.6
  - direct_menu: 0.9.2
  - documents: 0.13.1
  - external: true
  - federatedfilesharing: 0.3.0
  - federation: 0.1.0
  - files: 1.5.1
  - files_pdfviewer: 0.8.1
  - files_sharing: 0.10.0
  - files_texteditor: 2.1
  - files_trashbin: 0.9.0
  - files_versions: 1.3.0
  - files_videoplayer: 0.9.8
  - firstrunwizard: 1.1
  - gallery: 15.0.0
  - mail: 0.6.0
  - notifications: 0.3.0
  - provisioning_api: 0.5.0
  - systemtags: 0.3.0
  - tasks: 0.9.3
  - templateeditor: 0.1
  - updatenotification: 0.2.1
  - user_ldap: 0.9.0
Disabled:
  - encryption
  - files_antivirus
  - files_external
  - ownnote
  - user_external

The content of config/config.php:

{
    "system": {
        "updatechecker": false,
        "instanceid": "oc83hm92rscf",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "XXX:8080"
        ],
        "datadirectory": "\/var\/owncloud",
        "overwrite.cli.url": "http:\/\/XXX:8080\/owncloud",
        "dbtype": "mysql",
        "version": "9.1.1.3",
        "dbname": "owncloud",
        "dbhost": "localhost",
        "dbtableprefix": "oc_",
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "logtimezone": "UTC",
        "installed": true,
        "mail_smtpmode": "php",
        "mail_from_address": "webmaster",
        "mail_domain": "fim.uni-mannheim.de",
        "mail_smtphost": "fim.uni-mannheim.de",
        "mail_smtpsecure": "ssl",
        "mail_smtpport": "587",
        "ldapIgnoreNamingRules": false
    }
}

Client configuration

Browser: Chrome (not browser-related)

Operating system:

Logs

Web server error log

Insert your webserver log here

Server log (data/owncloud.log or data/nextcloud.log)

Exception: {"Exception":"Horde_Imap_Client_Exception_ServerResponse","Message":"IMAP error reported by server.","Code":0,"Trace":"#0 \/var\/www\/owncloud\/apps\/mail\/vendor\/pear-pear.horde.org\/Horde_Imap_Client\/Horde\/Imap\/Client\/Socket.php(4303): Horde_Imap_Client_Socket->_getLine(Object(Horde_Imap_Client_Interaction_Pipeline))\n#1 \/var\/www\/owncloud\/apps\/mail\/vendor\/pear-pear.horde.org\/Horde_Imap_Client\/Horde\/Imap\/Client\/Socket.php(4231): Horde_Imap_Client_Socket->_sendCmdChunk(Object(Horde_Imap_Client_Interaction_Pipeline), Array)\n#2 \/var\/www\/owncloud\/apps\/mail\/vendor\/pear-pear.horde.org\/Horde_Imap_Client\/Horde\/Imap\/Client\/Socket.php(1749): Horde_Imap_Client_Socket->_sendCmd(Object(Horde_Imap_Client_Interaction_Pipeline))\n#3 \/var\/www\/owncloud\/apps\/mail\/vendor\/pear-pear.horde.org\/Horde_Imap_Client\/Horde\/Imap\/Client\/Base.php(1726): Horde_Imap_Client_Socket->_status(Array, 63)\n#4 \/var\/www\/owncloud\/apps\/mail\/lib\/account.php(358): Horde_Imap_Client_Base->status(Array)\n#5 \/var\/www\/owncloud\/apps\/mail\/lib\/controller\/folderscontroller.php(62): OCA\\Mail\\Account->getListArray()\n#6 [internal function]: OCA\\Mail\\Controller\\FoldersController->index(3)\n#7 \/var\/www\/owncloud\/lib\/private\/AppFramework\/Http\/Dispatcher.php(159): call_user_func_array(Array, Array)\n#8 \/var\/www\/owncloud\/lib\/private\/AppFramework\/Http\/Dispatcher.php(89): OC\\AppFramework\\Http\\Dispatcher->executeController(Object(OCA\\Mail\\Controller\\FoldersController), 'index')\n#9 \/var\/www\/owncloud\/lib\/private\/AppFramework\/App.php(110): OC\\AppFramework\\Http\\Dispatcher->dispatch(Object(OCA\\Mail\\Controller\\FoldersController), 'index')\n#10 \/var\/www\/owncloud\/lib\/private\/AppFramework\/Routing\/RouteActionHandler.php(46): OC\\AppFramework\\App::main('FoldersControll...', 'index', Object(OC\\AppFramework\\DependencyInjection\\DIContainer), Array)\n#11 [internal function]: OC\\AppFramework\\Routing\\RouteActionHandler->__invoke(Array)\n#12 \/var\/www\/owncloud\/lib\/private\/Route\/Router.php(280): call_user_func(Object(OC\\AppFramework\\Routing\\RouteActionHandler), Array)\n#13 \/var\/www\/owncloud\/lib\/base.php(891): OC\\Route\\Router->match('\/apps\/mail\/acco...')\n#14 \/var\/www\/owncloud\/index.php(39): OC::handleRequest()\n#15 {main}","File":"\/var\/www\/owncloud\/apps\/mail\/vendor\/pear-pear.horde.org\/Horde_Imap_Client\/Horde\/Imap\/Client\/Socket.php","Line":4591}

Horde IMAP log (data/horde_imap.log)

>> Sat, 22 Oct 2016 10:17:50 +0000
>> Connection to: imap://XXX:993/
>> Server connection took 0.0928 seconds.
S: * OK [CAPABILITY IMAP4rev1 UIDPLUS CHILDREN NAMESPACE THREAD=ORDEREDSUBJECT THREAD=REFERENCES SORT QUOTA IDLE AUTH=PLAIN ACL ACL2=UNION] Courier-IMAP ready. Copyright 1998-2011 Double Precision, Inc.  See COPYING for distribution information.
C: 1 [INITIAL CLIENT RESPONSE (username:XXX)]
S: +
C: bmlrbGFzLmZydWVoYXVmAG5pa2xhcy5mcnVlaGF1ZgA0OjE1OjU2aDU6MTU6NTZo
S: 1 OK LOGIN Ok.
>> Command 1 took 0.3891 seconds.
C: 2 CAPABILITY
S: * CAPABILITY IMAP4rev1 UIDPLUS CHILDREN NAMESPACE THREAD=ORDEREDSUBJECT THREAD=REFERENCES SORT QUOTA IDLE AUTH=PLAIN ACL ACL2=UNION
S: 2 OK CAPABILITY completed
>> Command 2 took 0.0008 seconds.
C: 3 LIST "" *
S: * LIST (\HasNoChildren) "." "INBOX.Wichtig"
S: * LIST (\HasNoChildren) "." "INBOX.Sent"
S: * LIST (\HasNoChildren) "." "INBOX.Drafts"
S: * LIST (\HasNoChildren) "." "INBOX.T-Shirts.Anfragen_Offen"
S: * LIST (\HasChildren) "." "INBOX.T-Shirts"
S: * LIST (\HasNoChildren) "." "INBOX.NO-SPAM"
S: * LIST (\HasNoChildren) "." "INBOX.Spam"
S: * LIST (\HasNoChildren) "." "INBOX.Trash"
S: * LIST (\HasChildren) "." "INBOX.Offen"
S: * LIST (\HasNoChildren) "." "INBOX.Offen.To Do"
S: * LIST (\HasNoChildren) "." "INBOX.Offen.FYI"
S: * LIST (\HasNoChildren) "." "INBOX.Offen.Anfragen"
S: * LIST (\HasChildren) "." "INBOX.Archiv"
S: * LIST (\HasNoChildren) "." "INBOX.Archiv.Protokolle_Berichte"
S: * LIST (\HasNoChildren) "." "INBOX.Archiv.Fertig"
S: * LIST (\Marked \HasChildren) "." "INBOX"
S: 3 OK LIST completed
>> Command 3 took 0.0049 seconds.
C: 4 STATUS INBOX (MESSAGES RECENT UIDNEXT UIDVALIDITY UNSEEN)
C: 5 STATUS INBOX.Drafts (MESSAGES RECENT UIDNEXT UIDVALIDITY UNSEEN)
C: 6 STATUS INBOX.Sent (MESSAGES RECENT UIDNEXT UIDVALIDITY UNSEEN)
C: 7 STATUS INBOX.Spam (MESSAGES RECENT UIDNEXT UIDVALIDITY UNSEEN)
C: 8 STATUS INBOX.Trash (MESSAGES RECENT UIDNEXT UIDVALIDITY UNSEEN)
C: 9 STATUS INBOX.Archiv (MESSAGES RECENT UIDNEXT UIDVALIDITY UNSEEN)
C: 10 STATUS INBOX.Archiv.Fertig (MESSAGES RECENT UIDNEXT UIDVALIDITY UNSEEN)
C: 11 STATUS INBOX.Archiv.Protokolle_Berichte (MESSAGES RECENT UIDNEXT UIDVALIDITY UNSEEN)
C: 12 STATUS INBOX.NO-SPAM (MESSAGES RECENT UIDNEXT UIDVALIDITY UNSEEN)
C: 13 STATUS INBOX.Offen (MESSAGES RECENT UIDNEXT UIDVALIDITY UNSEEN)
C: 14 STATUS INBOX.Offen.Anfragen (MESSAGES RECENT UIDNEXT UIDVALIDITY UNSEEN)
C: 15 STATUS INBOX.Offen.FYI (MESSAGES RECENT UIDNEXT UIDVALIDITY UNSEEN)
C: 16 STATUS "INBOX.Offen.To Do" (MESSAGES RECENT UIDNEXT UIDVALIDITY UNSEEN)
C: 17 STATUS INBOX.T-Shirts (MESSAGES RECENT UIDNEXT UIDVALIDITY UNSEEN)
C: 18 STATUS INBOX.T-Shirts.Anfragen_Offen (MESSAGES RECENT UIDNEXT UIDVALIDITY UNSEEN)
C: 19 STATUS INBOX.Wichtig (MESSAGES RECENT UIDNEXT UIDVALIDITY UNSEEN)
S: * STATUS "INBOX" (MESSAGES 1739 RECENT 0 UIDNEXT 4517 UIDVALIDITY 1432140694 UNSEEN 108)
S: 4 OK STATUS Completed.
>> Command 4 took 0.0039 seconds.
S: * STATUS "INBOX.Drafts" (MESSAGES 0 RECENT 0 UIDNEXT 31 UIDVALIDITY 454770200 UNSEEN 0)
S: 5 OK STATUS Completed.
>> Command 5 took 0.0058 seconds.
S: * STATUS "INBOX.Sent" (MESSAGES 112 RECENT 0 UIDNEXT 115 UIDVALIDITY 454770898 UNSEEN 0)
S: 6 OK STATUS Completed.
>> Command 6 took 0.006 seconds.
S: * STATUS "INBOX.Spam" (MESSAGES 20 RECENT 0 UIDNEXT 221 UIDVALIDITY 461312016 UNSEEN 0)
S: 7 OK STATUS Completed.
>> Command 7 took 0.0062 seconds.
S: * STATUS "INBOX.Trash" (MESSAGES 32 RECENT 0 UIDNEXT 2754 UIDVALIDITY 1432207004 UNSEEN 28)
S: 8 OK STATUS Completed.
>> Command 8 took 0.0064 seconds.
S: * STATUS "INBOX.Archiv" (MESSAGES 1 RECENT 0 UIDNEXT 2 UIDVALIDITY 1432206923 UNSEEN 0)
S: 9 OK STATUS Completed.
>> Command 9 took 0.0066 seconds.
S: * STATUS "INBOX.Archiv.Fertig" (MESSAGES 0 RECENT 0 UIDNEXT 1 UIDVALIDITY 1432207542 UNSEEN 0)
S: 10 OK STATUS Completed.
>> Command 10 took 0.0067 seconds.
S: * STATUS "INBOX.Archiv.Protokolle_Berichte" (MESSAGES 3 RECENT 0 UIDNEXT 4 UIDVALIDITY 1432207625 UNSEEN 0)
S: 11 OK STATUS Completed.
>> Command 11 took 0.0069 seconds.
S: 12 NO [ALERT] STATUS failed
>> Command 12 took 0.0069 seconds.
S: * STATUS "INBOX.Offen" (MESSAGES 0 RECENT 0 UIDNEXT 1 UIDVALIDITY 1432207522 UNSEEN 0)
S: 13 OK STATUS Completed.
>> Command 13 took 0.0075 seconds.
S: * STATUS "INBOX.Offen.Anfragen" (MESSAGES 0 RECENT 0 UIDNEXT 7 UIDVALIDITY 1432207590 UNSEEN 0)
S: 14 OK STATUS Completed.
>> Command 14 took 0.0077 seconds.
S: * STATUS "INBOX.Offen.FYI" (MESSAGES 0 RECENT 0 UIDNEXT 6 UIDVALIDITY 1432207561 UNSEEN 0)
S: 15 OK STATUS Completed.
>> Command 15 took 0.0079 seconds.
S: * STATUS "INBOX.Offen.To Do" (MESSAGES 0 RECENT 0 UIDNEXT 1 UIDVALIDITY 1432207564 UNSEEN 0)
S: 16 OK STATUS Completed.
>> Command 16 took 0.0081 seconds.
S: * STATUS "INBOX.T-Shirts" (MESSAGES 10 RECENT 0 UIDNEXT 11 UIDVALIDITY 452704676 UNSEEN 0)
S: 17 OK STATUS Completed.
>> Command 17 took 0.0442 seconds.
S: * STATUS "INBOX.T-Shirts.Anfragen_Offen" (MESSAGES 5 RECENT 0 UIDNEXT 7 UIDVALIDITY 452704717 UNSEEN 0)
S: 18 OK STATUS Completed.
>> Command 18 took 0.0447 seconds.
S: * STATUS "INBOX.Wichtig" (MESSAGES 4 RECENT 0 UIDNEXT 6 UIDVALIDITY 457296250 UNSEEN 0)
S: 19 OK STATUS Completed.
>> Command 19 took 0.0451 seconds.
C: 20 LOGOUT
S: * BYE Courier-IMAP server shutting down
S: 20 OK LOGOUT completed
>> Command 20 took 0.0008 seconds.

Horde SMTP log (data/horde_smtp.log)

>> Sat, 22 Oct 2016 10:16:15 +0000
>> Connection to: smtp:/XXX:465
S: 220 XXX Postfix SMTP
C: EHLO XXX
S: 250-XXX
S: 250-PIPELINING
S: 250-SIZE 209715200
S: 250-ETRN
S: 250-AUTH PLAIN LOGIN
S: 250-AUTH=PLAIN LOGIN
S: 250-ENHANCEDSTATUSCODES
S: 250-8BITMIME
S: 250 DSN
[AUTH Command - method: PLAIN; username: XXX]
S: 235 2.7.0 Authentication successful
C: QUIT
S: 221 2.0.0 Bye

1. to develop bug

Source

Zahlii

Most helpful comment

The specific header I'm seeing that causes problems is:

          To: undisclosed-recipients:;

sldobson on 19 Nov 2016

👍2

All 9 comments

12 NO [ALERT] STATUS failed >> Command 12 took 0.0069 seconds.

That looks suspicious. Maybe one of the folders is not subscribed? I think I recently saw a similar report.

ChristophWurst on 22 Oct 2016

@ChristophWurst I checked with Thunderbird and indeed had one folder not subscribed called "NO-SPAM". However, if I subscribe using Thunderbird, it still throws the same error.

ADD: Thunderbird itself complains it's not able to load NO-SPAM.
ADD2: Deleted the folder with Thunderbird (whatever that does, no idea if it deletes it on the server) and still the same error persists.

Zahlii on 22 Oct 2016

@ChristophWurst Okay..Deleting the folder in Thunderbird put it into Trash/NO-SPAM where it stillw asn't working.

I deleted it again and it is working correctly now.

However I think the mail app should be able to handle this kind of failures somehow!

Zahlii on 22 Oct 2016

However I think the mail app should be able to handle this kind of failures somehow!

Of course it should. Do you know PHP? 😉

ChristophWurst on 22 Oct 2016

This is happening to me. I've tracked it down to the presence of any mail addressed to "undisclosed recipients". If I move only these mails out of the folder then the 500 error goes away and I can view the remaining contents of the folder as usual. Hope this helps.

sldobson on 19 Nov 2016

The specific header I'm seeing that causes problems is:

          To: undisclosed-recipients:;

sldobson on 19 Nov 2016

👍2

I am very weak in PHP and do not know anything about this app, but I think simplistic fix is adding in mail/lib/Model/ConvertAddresses.php
use Horde_Mail_Rfc822;

And modify function convertAddressList at the end of the file to

   protected function convertAddressList($envelope) {
            $list = [];
            foreach ($envelope as $t) {
              if (Horde_Mail_Rfc822::isValidInetAddress($t)) {
                    $list[] = $this->hordeToAssoc($t);
              }
            }
            return $list;
    }

Which will ignore "undisclosed-recipients" and other invalid addresses. Not sure, if it will brake anything else, but at least it shows list of e-mails in folder ...

girts-ziemelis on 18 Jan 2017

@sldobson @girts-ziemelis the issue you describe was fixed by @nickvergessen in https://github.com/nextcloud/mail/pull/339.

Since @Zahlii could resolve their problem I'm closing this ticket now.

ChristophWurst on 2 Aug 2017

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.