Courier IMAP setup and Delete

KlausdB commented 6 years ago

Steps to reproduce

Attempt to setup IMAP account (using different agents: Firefox, Chrome, Edge)
Delete email after setup

Actual behaviour

When attempting to setup an email account (on Courier-based Server):

If the account has already been used by another mail client, Setup fails with message: "Error while loading the Selected Account" and no folders are visible or accessible;
If an account on that Server has not been used before by any other client, it will connect and display as expected, however, will not allow deletion of emails with message: "Error while deleting message.

Setting up other accounts on different mail servers works without issue.

Mail app

**Mail app version: 0.7.9

**Mailserver or service: standard ISP using Courier/Postfix

**Transport security - IMAP: None, SSL, TLS, STARTTLS all tried.

**Transport security - SMTP: None, SSL, TLS, STARTTLS all tried

**Number of accounts: 2

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

Server configuration

Operating system: Linux 3.10.0-693.17.1.el7.x86_64 #1 SMP Thu Jan 25 20:13:58 UTC 2018 x86_64

Webserver: Apache/2.4.6 (CentOS) OpenSSL/1.0.2k-fips PHP/5.4.16 (fpm-fcgi)

Database: mysql 5.5.56

PHP version: 5.6.25 Modules loaded: Core, date, ereg, libxml, openssl, pcre, zlib, filter, hash, Reflection, SPL, session, standard, cgi-fcgi, bz2, calendar, ctype, curl, dom, mbstring, fileinfo, ftp, gd, gettext, iconv, intl, ldap, exif, mysqlnd, PDO, Phar, posix, shmop, SimpleXML, sockets, sqlite3, sysvmsg, sysvsem, sysvshm, tokenizer, xml, xmlwriter, xsl, zip, mysql, mysqli, pdo_mysql, pdo_sqlite, wddx, xmlreader, json, smbclient, mhash, libsmbclient

Nextcloud version: 12.0.4 - 12.0.4.3

Updated from an older version or fresh install: Fresh

List of activated apps: Enabled:

activity: 2.5.2
announcementcenter: 3.1.1
calendar: 1.5.7
comments: 1.2.0
contacts: 2.0.1
dav: 1.3.0
deck: 0.3.0
federatedfilesharing: 1.2.0
federation: 1.2.0
files: 1.7.2
files_accesscontrol: 1.2.5
files_external: 1.3.0
files_pdfviewer: 1.1.1
files_sharing: 1.4.0
files_texteditor: 2.4.1
files_trashbin: 1.2.0
files_versions: 1.5.0
files_videoplayer: 1.1.0
firstrunwizard: 2.1
gallery: 17.0.0
groupfolders: 1.2.0
issuetemplate: 0.3.0
logreader: 2.0.0
lookup_server_connector: 1.0.0
mail: 0.7.9
nextcloud_announcements: 1.1
notes: 2.3.2
notifications: 2.0.0
oauth2: 1.0.5
onlyoffice: 1.2.0
password_policy: 1.2.2
provisioning_api: 1.2.0
serverinfo: 1.2.0
sharebymail: 1.2.0
socialsharing_email: 1.0.3
survey_client: 1.0.0
systemtags: 1.2.0
tasks: 0.9.5
telephoneprovider: 1.0.1
theming: 1.3.0
twofactor_backupcodes: 1.1.1
updatenotification: 1.2.0
user_ldap: 1.2.1
w2g2: 0.9.9

workflowengine: 1.2.0

If you have access to your command line run e.g.:
sudo -u www-data php occ app:list
from within your server installation folder

The content of config/config.php:

{ "passwordsalt": "***REMOVED SENSITIVE VALUE***", "secret": "***REMOVED SENSITIVE VALUE***", "trusted_domains": [ "localhost", "server..lan", "192.168.1.253", "203..*.*.*", "office..com.au", "office..com.au" ], "datadirectory": "\/var\/lib\/nethserver\/nextcloud\/", "overwrite.cli.url": "http:\/\/localhost", "dbtype": "mysql", "version": "12.0.4.3", "dbname": "nextcloud", "dbhost": "localhost", "dbport": "", "dbtableprefix": "oc_", "dbuser": "***REMOVED SENSITIVE VALUE***", "dbpassword": "***REMOVED SENSITIVE VALUE***", "logtimezone": "UTC", "installed": true, "instanceid": "ocg7qndbq9bd", "ldapIgnoreNamingRules": false, "ldapProviderFactory": "\\OCA\\User_LDAP\\LDAPProviderFactory", "maintenance": false, "loglevel": 2, "mail_domain": ".com.au", "mail_smtpmode": "php", "mail_smtpauthtype": "LOGIN", "mail_from_address": "nextcloud" } ```

Client configuration

Browser: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:57.0) Gecko/20100101 Firefox/57.0

Operating system:Win10 x64

Logs

Web server error log

Insert your webserver log here

Server log (data/nextcloud.log)

``` Setup Fail: {"reqId":"Wm7K33ASFENau6ZTtWWHDwAAAAo","level":3,"time":"2018-01-29T07:18:56+00:00","remoteAddr":"202.14.148.23","user":"9B875F98-B0DF-4EDA-A5EF-0E3C8641C4A6","app":"index","method":"GET","url":"\/nextcloud\/index.php\/apps\/mail\/api\/accounts\/10\/folders","message":"Exception: {\"Exception\":\"Horde_Imap_Client_Exception_ServerResponse\",\"Message\":\"IMAP error reported by server.\",\"Code\":0,\"Trace\":\"#0 \\\/usr\\\/share\\\/nextcloud\\\/apps\\\/mail\\\/vendor\\\/pear-pear.horde.org\\\/Horde_Imap_Client\\\/Horde\\\/Imap\\\/Client\\\/Socket.php(4302): Horde_Imap_Client_Socket->_getLine(Object(Horde_Imap_Client_Interaction_Pipeline))\\n#1 \\\/usr\\\/share\\\/nextcloud\\\/apps\\\/mail\\\/vendor\\\/pear-pear.horde.org\\\/Horde_Imap_Client\\\/Horde\\\/Imap\\\/Client\\\/Socket.php(4230): Horde_Imap_Client_Socket->_sendCmdChunk(Object(Horde_Imap_Client_Interaction_Pipeline), Array)\\n#2 \\\/usr\\\/share\\\/nextcloud\\\/apps\\\/mail\\\/vendor\\\/pear-pear.horde.org\\\/Horde_Imap_Client\\\/Horde\\\/Imap\\\/Client\\\/Socket.php(1751): Horde_Imap_Client_Socket->_sendCmd(Object(Horde_Imap_Client_Interaction_Pipeline))\\n#3 \\\/usr\\\/share\\\/nextcloud\\\/apps\\\/mail\\\/vendor\\\/pear-pear.horde.org\\\/Horde_Imap_Client\\\/Horde\\\/Imap\\\/Client\\\/Base.php(1728): Horde_Imap_Client_Socket->_status(Array, 8205)\\n#4 \\\/usr\\\/share\\\/nextcloud\\\/apps\\\/mail\\\/vendor\\\/pear-pear.horde.org\\\/Horde_Imap_Client\\\/Horde\\\/Imap\\\/Client\\\/Base.php(4034): Horde_Imap_Client_Base->status('INBOX.customfla...', 8713)\\n#5 \\\/usr\\\/share\\\/nextcloud\\\/apps\\\/mail\\\/vendor\\\/pear-pear.horde.org\\\/Horde_Imap_Client\\\/Horde\\\/Imap\\\/Client\\\/Base.php(3585): Horde_Imap_Client_Base->_syncStatus('INBOX.customfla...')\\n#6 \\\/usr\\\/share\\\/nextcloud\\\/apps\\\/mail\\\/lib\\\/Service\\\/FolderMapper.php(56): Horde_Imap_Client_Base->getSyncToken('INBOX.customfla...')\\n#7 \\\/usr\\\/share\\\/nextcloud\\\/apps\\\/mail\\\/lib\\\/Service\\\/MailManager.php(70): OCA\\\\Mail\\\\Service\\\\FolderMapper->getFolders(Object(OCA\\\\Mail\\\\Account), Object(Horde_Imap_Client_Socket))\\n#8 \\\/usr\\\/share\\\/nextcloud\\\/apps\\\/mail\\\/lib\\\/Controller\\\/FoldersController.php(71): OCA\\\\Mail\\\\Service\\\\MailManager->getFolders(Object(OCA\\\\Mail\\\\Account))\\n#9 [internal function]: OCA\\\\Mail\\\\Controller\\\\FoldersController->index(10)\\n#10 \\\/usr\\\/share\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Http\\\/Dispatcher.php(160): call_user_func_array(Array, Array)\\n#11 \\\/usr\\\/share\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Http\\\/Dispatcher.php(90): OC\\\\AppFramework\\\\Http\\\\Dispatcher->executeController(Object(OCA\\\\Mail\\\\Controller\\\\FoldersController), 'index')\\n#12 \\\/usr\\\/share\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/App.php(114): OC\\\\AppFramework\\\\Http\\\\Dispatcher->dispatch(Object(OCA\\\\Mail\\\\Controller\\\\FoldersController), 'index')\\n#13 \\\/usr\\\/share\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Routing\\\/RouteActionHandler.php(47): OC\\\\AppFramework\\\\App::main('FoldersControll...', 'index', Object(OC\\\\AppFramework\\\\DependencyInjection\\\\DIContainer), Array)\\n#14 [internal function]: OC\\\\AppFramework\\\\Routing\\\\RouteActionHandler->__invoke(Array)\\n#15 \\\/usr\\\/share\\\/nextcloud\\\/lib\\\/private\\\/Route\\\/Router.php(299): call_user_func(Object(OC\\\\AppFramework\\\\Routing\\\\RouteActionHandler), Array)\\n#16 \\\/usr\\\/share\\\/nextcloud\\\/lib\\\/base.php(1004): OC\\\\Route\\\\Router->match('\\\/apps\\\/mail\\\/api\\\/...')\\n#17 \\\/usr\\\/share\\\/nextcloud\\\/index.php(48): OC::handleRequest()\\n#18 {main}\",\"File\":\"\\\/usr\\\/share\\\/nextcloud\\\/apps\\\/mail\\\/vendor\\\/pear-pear.horde.org\\\/Horde_Imap_Client\\\/Horde\\\/Imap\\\/Client\\\/Socket.php\",\"Line\":4590}","userAgent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"12.0.4.3"} Delete Fail: {"reqId":"Wm7MtrW1WK-F1rjx1V280wAAAAs","level":3,"time":"2018-01-29T07:26:47+00:00","remoteAddr":"202.14.148.23","user":"9B875F98-B0DF-4EDA-A5EF-0E3C8641C4A6","app":"index","method":"DELETE","url":"\/nextcloud\/index.php\/apps\/mail\/api\/accounts\/9\/folders\/SU5CT1g%3D\/messages\/1","message":"Exception: {\"Exception\":\"Horde_Imap_Client_Exception_ServerResponse\",\"Message\":\"IMAP error reported by server.\",\"Code\":0,\"Trace\":\"#0 \\\/usr\\\/share\\\/nextcloud\\\/apps\\\/mail\\\/vendor\\\/pear-pear.horde.org\\\/Horde_Imap_Client\\\/Horde\\\/Imap\\\/Client\\\/Socket.php(4302): Horde_Imap_Client_Socket->_getLine(Object(Horde_Imap_Client_Interaction_Pipeline))\\n#1 \\\/usr\\\/share\\\/nextcloud\\\/apps\\\/mail\\\/vendor\\\/pear-pear.horde.org\\\/Horde_Imap_Client\\\/Horde\\\/Imap\\\/Client\\\/Socket.php(4230): Horde_Imap_Client_Socket->_sendCmdChunk(Object(Horde_Imap_Client_Interaction_Pipeline), Array)\\n#2 \\\/usr\\\/share\\\/nextcloud\\\/apps\\\/mail\\\/vendor\\\/pear-pear.horde.org\\\/Horde_Imap_Client\\\/Horde\\\/Imap\\\/Client\\\/Socket.php(3678): Horde_Imap_Client_Socket->_sendCmd(Object(Horde_Imap_Client_Interaction_Pipeline))\\n#3 \\\/usr\\\/share\\\/nextcloud\\\/apps\\\/mail\\\/vendor\\\/pear-pear.horde.org\\\/Horde_Imap_Client\\\/Horde\\\/Imap\\\/Client\\\/Base.php(2957): Horde_Imap_Client_Socket->_copy(Object(Horde_Imap_Client_Mailbox), Array)\\n#4 \\\/usr\\\/share\\\/nextcloud\\\/apps\\\/mail\\\/lib\\\/Account.php(464): Horde_Imap_Client_Base->copy(Object(Horde_Imap_Client_Mailbox), Object(Horde_Imap_Client_Mailbox), Array)\\n#5 \\\/usr\\\/share\\\/nextcloud\\\/apps\\\/mail\\\/lib\\\/Controller\\\/MessagesController.php(357): OCA\\\\Mail\\\\Account->deleteMessage('INBOX', '1')\\n#6 [internal function]: OCA\\\\Mail\\\\Controller\\\\MessagesController->destroy(9, 'SU5CT1g=', '1')\\n#7 \\\/usr\\\/share\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Http\\\/Dispatcher.php(160): call_user_func_array(Array, Array)\\n#8 \\\/usr\\\/share\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Http\\\/Dispatcher.php(90): OC\\\\AppFramework\\\\Http\\\\Dispatcher->executeController(Object(OCA\\\\Mail\\\\Controller\\\\MessagesController), 'destroy')\\n#9 \\\/usr\\\/share\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/App.php(114): OC\\\\AppFramework\\\\Http\\\\Dispatcher->dispatch(Object(OCA\\\\Mail\\\\Controller\\\\MessagesController), 'destroy')\\n#10 \\\/usr\\\/share\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Routing\\\/RouteActionHandler.php(47): OC\\\\AppFramework\\\\App::main('MessagesControl...', 'destroy', Object(OC\\\\AppFramework\\\\DependencyInjection\\\\DIContainer), Array)\\n#11 [internal function]: OC\\\\AppFramework\\\\Routing\\\\RouteActionHandler->__invoke(Array)\\n#12 \\\/usr\\\/share\\\/nextcloud\\\/lib\\\/private\\\/Route\\\/Router.php(299): call_user_func(Object(OC\\\\AppFramework\\\\Routing\\\\RouteActionHandler), Array)\\n#13 \\\/usr\\\/share\\\/nextcloud\\\/lib\\\/base.php(1004): OC\\\\Route\\\\Router->match('\\\/apps\\\/mail\\\/api\\\/...')\\n#14 \\\/usr\\\/share\\\/nextcloud\\\/index.php(48): OC::handleRequest()\\n#15 {main}\",\"File\":\"\\\/usr\\\/share\\\/nextcloud\\\/apps\\\/mail\\\/vendor\\\/pear-pear.horde.org\\\/Horde_Imap_Client\\\/Horde\\\/Imap\\\/Client\\\/Socket.php\",\"Line\":4590}","userAgent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"12.0.4.3"} ```

Horde IMAP log (data/horde_imap.log)

Failed Account Setup: >> Mon, 29 Jan 2018 12:45:36 +0000 >> Connection to: imap://mail.iig.com.au:993/ >> Server connection took 0.1485 seconds. S: * OK [CAPABILITY IMAP4rev1 UIDPLUS CHILDREN NAMESPACE THREAD=ORDEREDSUBJECT THREAD=REFERENCES SORT AUTH=PLAIN ACL ACL2=UNION] Courier-IMAP ready. Copyright 1998-2004 Double Precision, Inc. See COPYING for distribution information. C: 1 [INITIAL CLIENT RESPONSE (username: cns02***)] S: + C: Y25zMDI2MDgAY25zMDI2MDgAMjYwOHRpa2E= S: 1 OK LOGIN Ok. >> Command 1 took 0.0726 seconds. C: 2 CAPABILITY S: * CAPABILITY IMAP4rev1 UIDPLUS CHILDREN NAMESPACE THREAD=ORDEREDSUBJECT THREAD=REFERENCES SORT AUTH=PLAIN ACL ACL2=UNION S: 2 OK CAPABILITY completed >> Command 2 took 0.0329 seconds. C: 3 LOGOUT S: * BYE Courier-IMAP server shutting down S: 3 OK LOGOUT completed >> Command 3 took 0.0326 seconds. Failed Item Delete: >> Mon, 29 Jan 2018 12:47:07 +0000 >> Connection to: imap://mail.iig.com.au/ >> Server connection took 0.0322 seconds. S: * OK [CAPABILITY IMAP4rev1 UIDPLUS CHILDREN NAMESPACE THREAD=ORDEREDSUBJECT THREAD=REFERENCES SORT ACL ACL2=UNION] Courier-IMAP ready. Copyright 1998-2004 Double Precision, Inc. See COPYING for distribution information. C: 1 LOGIN mbx15** [PASSWORD] S: 1 OK LOGIN Ok. >> Command 1 took 0.0448 seconds. C: 2 CAPABILITY S: * CAPABILITY IMAP4rev1 UIDPLUS CHILDREN NAMESPACE THREAD=ORDEREDSUBJECT THREAD=REFERENCES SORT ACL ACL2=UNION S: 2 OK CAPABILITY completed >> Command 2 took 0.0321 seconds. C: 3 LIST "" * S: * LIST (\HasNoChildren) "." "INBOX.Drafts" S: * LIST (\HasNoChildren) "." "INBOX.Deleted Items" S: * LIST (\HasNoChildren) "." "INBOX.Sent Items" S: * LIST (\Unmarked \HasChildren) "." "INBOX" S: 3 OK LIST completed >> Command 3 took 0.0325 seconds. C: 4 SELECT INBOX S: * FLAGS (\Draft \Answered \Flagged \Deleted \Seen \Recent) S: * OK [PERMANENTFLAGS (\* \Draft \Answered \Flagged \Deleted \Seen)] Limited S: * 4 EXISTS S: * 0 RECENT S: * OK [UIDVALIDITY 1516931820] Ok S: * OK [MYRIGHTS "acdilrsw"] ACL S: 4 OK [READ-WRITE] Ok >> Command 4 took 0.2298 seconds. C: 5 UID COPY 1 Trash S: 5 NO Error in IMAP command received by server. >> Command 5 took 0.0328 seconds. C: 6 LOGOUT S: * BYE Courier-IMAP server shutting down S: 6 OK LOGOUT completed >> Command 6 took 0.0323 seconds. ```

Horde SMTP log (data/horde_smtp.log)

``` Insert your horde SMTP log here, see https://github.com/nextcloud/mail#debug-mode ```

Browser log

``` Insert your browser log here, this could for example include: a) The javascript console log b) The network log c) ... ```

--- Want to back this issue? **[Post a bounty on it!](https://www.bountysource.com/issues/54344524-courier-imap-setup-and-delete?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).

ChristophWurst commented 6 years ago

Insert your horde IMAP log here

Your report is missing a crucial info.

KlausdB commented 6 years ago

Edit: Ok, I found some instructions here: https://libraries.io/github/nextcloud/mail but not sure if it is still relevant - entered the code in config/config.php but no logs appear.

@ChristophWurst I can't find a horde IMAP log on my system (checked nextcloud/data/ and everywhere else);
the link to instructions for that in the issue template just goes back the main page, I can't see/find an anchor #debug-mode with instructions to enable it on there; I assume there is a loglevel switch entry somewhere, but can't find it; my install is on NethServer with NextCloud integrated.

ChristophWurst commented 6 years ago

Sorry, looks like our issue template is outdate. Simple enable debug mode and those imap (and smtp) logs will be generated.

KlausdB commented 6 years ago

OK, Got that now and inserted imap log into the original post. Thanks.

ChristophWurst commented 6 years ago

☑️ Folder list

C: 3 LIST "" S: LIST (\HasNoChildren) "." "INBOX.Drafts" S: LIST (\HasNoChildren) "." "INBOX.Deleted Items" S: LIST (\HasNoChildren) "." "INBOX.Sent Items" S: * LIST (\Unmarked \HasChildren) "." "INBOX"

💥 Copying the message to the Trash folder

C: 5 UID COPY 1 Trash S: 5 NO Error in IMAP command received by server.

-> this obviously fails as there is no Trash folder.

ChristophWurst commented 6 years ago

This either means

We fail to detect the correct trash folder
The trash folder is not created if it does not exist

KlausdB commented 6 years ago

I can confirm creating a /.Trash folder structure resolved the delete issue - the default on that server is /.Deleted Items. Therefore assume the client is not creating its required/expected folder structure;

In a similar light, the existence of /.INBOX, .subscriptions and .customflags - created by another IMAP client - stopped the creation/loading of the account. Removed those and all worked as expected. I assume if another client connects and creates those again, the account will fail to load.

ChristophWurst commented 6 years ago

In a similar light, the existence of /.INBOX, .subscriptions and .customflags - created by another IMAP client - stopped the creation/loading of the account. Removed those and all worked as expected. I assume if another client connects and creates those again, the account will fail to load.

Sounds similar to https://github.com/nextcloud/mail/blob/0961f1d6ba820881a52520ee66ce6674a7894d6e/lib/Service/FolderMapper.php#L53 - mailboxes that should be ignored

KlausdB commented 6 years ago

Yes, indeed. With access to the mail server it was simple enough to just remove those files - don't know which client created them (back in 2007!). At this stage just handy to know what causes the issue.

Auto creation of 'Trash' folder if not exists would be handy.

jgoerzen commented 5 years ago

Another issue I found here:

If .INBOX.Trash exists, deletion of messages fails, with this in the log:

C: 4 STATUS INBOX.INBOX (MESSAGES) S: 4 NO Mailbox does not exist, or must be subscribed to.

In this case, .INBOX did not exist, just .INBOX.Trash. Apparently it tried to use this as the deletion folder?

ChristophWurst commented 2 years ago

could you try and see if this still happens?

KlausdB commented 2 years ago

Still occurring. Created a clean mailbox on Courier based server; Mail 1.11.1 is unable to create the Trash mailbox.

ChristophWurst commented 2 weeks ago

@SebastianKrupinski is this the setup issue you experienced as well? We might want to redo https://github.com/nextcloud/mail/pull/9552 as PR (not master push)

SebastianKrupinski commented 2 weeks ago

@ChristophWurst No this is a different issue, looks like the initial connection/sync is NOT mapping the folders correctly. The issue I experienced was the initial sync failing because it was trying to access a folder that was NOT selectable.

nextcloud / mail