Mail: Mail is not displayed, JS running ready

Created on 5 Oct 2017  Â·  12Comments  Â·  Source: nextcloud/mail

Steps to reproduce

Upgrade from Nextcloud 11 to 12
Upgrade mail plugin to 0.7.3
Try to check mails

Expected behaviour

The list of folders is shown, the mail titles of the current folder are shown, the selected mail is shown

Actual behaviour

The list of folders is shown, the mail titles of the current folder are shown, the selected mail is not shown, just the roller while one core stays busy. This blocks the whole app on Firefox. On Chrome you can still change folders and on some the mails are displayed just fine. I was not able to find a true pattern here. It has apparently nothing to do with number of mails in the folder, mail formatting (html/text/mixed) or sender. The Chrome javascript console however claims some cache error.

General server configuration

Operating system: Linux J6868 2.6.32-5-xen-686 #1 SMP Sun Jul 13 02:47:03 UTC 2014 i686

Web server: nginx/1.6.2 (fpm-fcgi)

Database: mysql 5.5.57

PHP version: 5.6.31-1~dotdeb+7.1


PHP-modules loaded

 - Core
 - date
 - ereg
 - libxml
 - openssl
 - pcre
 - zlib
 - bcmath
 - bz2
 - calendar
 - ctype
 - dba
 - dom
 - hash
 - fileinfo
 - filter
 - ftp
 - gettext
 - SPL
 - iconv
 - json
 - mbstring
 - session
 - posix
 - Reflection
 - standard
 - shmop
 - SimpleXML
 - soap
 - sockets
 - Phar
 - exif
 - sysvmsg
 - sysvsem
 - sysvshm
 - tokenizer
 - wddx
 - xml
 - xmlreader
 - xmlwriter
 - zip
 - cgi-fcgi
 - PDO
 - curl
 - gd
 - memcache
 - mysql
 - mysqli
 - pdo_mysql
 - pdo_sqlite
 - redis
 - sqlite3
 - xsl
 - mhash
 - Zend OPcache

Nextcloud configuration

Nextcloud version: 12.0.3 - 12.0.3.3

Updated from an older Nextcloud/ownCloud or fresh install: 11.0.x

Where did you install Nextcloud from: web-installer

Are you using external storage, if yes which one: files_external is disabled

Are you using encryption: no

Are you using an external user-backend, if yes which one: n/a

 - activity: 2.5.2
 - bruteforcesettings: 1.0.2
 - calendar: 1.5.5
 - comments: 1.2.0
 - contacts: 2.0.1
 - dav: 1.3.0
 - federatedfilesharing: 1.2.0
 - files: 1.7.2
 - 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
 - issuetemplate: 0.2.2
 - logreader: 2.0.0
 - lookup_server_connector: 1.0.0
 - mail: 0.7.3
 - nextcloud_announcements: 1.1
 - notifications: 2.0.0
 - oauth2: 1.0.5
 - password_policy: 1.2.2
 - provisioning_api: 1.2.0
 - serverinfo: 1.2.0
 - sharebymail: 1.2.0
 - survey_client: 1.0.0
 - systemtags: 1.2.0
 - theming: 1.3.0
 - twofactor_backupcodes: 1.1.1
 - updatenotification: 1.2.0
 - workflowengine: 1.2.0


Disabled apps

 - admin_audit
 - audioplayer
 - encryption
 - federation
 - files_external
 - files_mv
 - user_external
 - user_ldap


Content of config/config.php

{
    "instanceid": "5112297a1ec88",
    "passwordsalt": "***REMOVED SENSITIVE VALUE***",
    "datadirectory": "\/var\/www\/ocdata",
    "dbtype": "mysql",
    "version": "12.0.3.3",
    "installed": true,
    "loglevel": 1,
    "maintenance": false,
    "forcessl": true,
    "theme": "",
    "maxZipInputSize": 1073741824,
    "allowZipDownload": true,
    "trusted_domains": [
        "cloud.foxbow.de"
    ],
    "filelocking.enabled": "true",
    "mail_from_address": "cloud",
    "mail_smtpmode": "php",
    "mail_domain": "foxbow.de",
    "secret": "***REMOVED SENSITIVE VALUE***",
    "dbname": "owncloud",
    "dbhost": "localhost",
    "dbuser": "***REMOVED SENSITIVE VALUE***",
    "dbpassword": "***REMOVED SENSITIVE VALUE***",
    "trashbin_retention_obligation": "auto",
    "updater.secret": "***REMOVED SENSITIVE VALUE***",
    "overwrite.cli.url": "https:\/\/cloud.foxbow.de"
}

Client configuration

Browser: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/61.0.3163.79 Chrome/61.0.3163.79 Safari/537.36

Operating system: Ubuntu 16.04

Logs


Nextcloud log (data/nextcloud.log)

Info    mail    Updating draft <627204655> in account <1>   2017-10-05T09:14:55+0200
Info    mail    Updating draft <627204654> in account <1>   2017-10-05T09:14:50+0200
Info    mail    Updating draft <627204653> in account <1>   2017-10-05T09:14:38+0200
Info    mail    Updating draft <627204652> in account <1>   2017-10-05T09:13:43+0200
Info    mail    Updating draft <627204651> in account <1>   2017-10-05T09:13:05+0200
Info    mail    Updating draft <627204650> in account <1>   2017-10-05T09:12:53+0200
Info    mail    Updating draft <627204649> in account <1>   2017-10-05T09:12:49+0200
Info    mail    Updating draft <627204648> in account <1>   2017-10-05T09:11:16+0200
Info    mail    Updating draft <627204647> in account <1>   2017-10-05T09:11:11+0200
Info    mail    Updating draft <627204646> in account <1>   2017-10-05T09:10:49+0200
Info    mail    Updating draft <627204645> in account <1>   2017-10-05T09:10:42+0200
Info    mail    Updating draft <627204644> in account <1>   2017-10-05T09:10:10+0200
Info    mail    Updating draft <627204643> in account <1>   2017-10-05T09:08:52+0200
Info    mail    Updating draft <627204642> in account <1>   2017-10-05T09:07:38+0200
Info    mail    Updating draft <627204641> in account <1>   2017-10-05T09:07:19+0200
Info    mail    Updating draft <627204640> in account <1>   2017-10-05T09:06:21+0200
Info    mail    Updating draft <627204639> in account <1>   2017-10-05T09:05:59+0200
Info    mail    Updating draft <627204638> in account <1>   2017-10-05T09:05:57+0200


Browser log

JQMIGRATE: Migrate is installed, version 1.4.0
init.js:25 Starting Mail …
cache.js:47 initializing cache…
js.storage.js:152 Uncaught (in promise) RangeError: Invalid string length
    at JSON.stringify (<anonymous>)
    at Object._set (js.storage.js:152)
    at Object._callMethod (js.storage.js:438)
    at Object.set (js.storage.js:461)
    at Object.addMessage (cache.js:108)
    at messagecontroller.js:87
    at <anonymous>
DevTools failed to parse SourceMap: https://cloud.foxbow.de/core/vendor/purify.min.js.map


Want to back this issue? Post a bounty on it! We accept bounties via Bountysource.

3. to review bug

Most helpful comment

Yes :) it's the same. Thx

This is from the Firefox log with a large message ID where it gets stuck:
index.php/apps/mail/accounts/1/folders/SU5CT1g%3D/messages/32627360

From an other mailbox where i can show the messages, with shorter ID:
index.php/apps/mail/accounts/4/folders/SU5CT1g=/messages/1329

Best regards

Ah, as much as I know, opera used the same engine as chrome.

All 12 comments

When debugging the javascript in Chrome, I can see where it fails. In js.storage.js an array is being stored as an item in the "messages" set. Apparently this is the basic mail info with the headers, like title, cc, reply-to etc. This is converted via JSON.stringify and that one throws an uncaught exception: Uncaught (in promise) RangeError: Invalid string length

Unfortunately I have no clue which string that may be and where the actual source is to add a try/catch block around it for further investigation. Also the callstack is not very informative either. So if anyone could either tell me where to find the sources in question, the point in the mail, where this is triggered or even a 'better' JS debugger I would offer to investigate further - especially as it seems that I'm the only one being able to reproduce this so far.

I found a pattern! Messages that are displayed properly have a low message ID, about 0 to 300. The failing messages have HUGE IDs, like 627173617 or 627182862 which kind of feels like an overflow issue. Fun thing is that these apparently worked just fine in Nextcloud 11.

I found a pattern! Messages that are displayed properly have a low message ID, about 0 to 300. The failing messages have HUGE IDs, like 627173617 or 627182862 which kind of feels like an overflow issue.

Wow, good finding.

Fun thing is that these apparently worked just fine in Nextcloud 11.

Well, maybe your UIDs were just lower back then 😉

I don't know if it depends on the same issue but the behaviour is similar.

Steps to reproduce

Upgrade from Nextcloud 11 to 12
Upgrade mail plugin to 0.7.3
Try to check mails
Mailbox from IMAP: imap.de.aol.com with 177 mails

Expected behaviour

The selected mail is shown

Actual behaviour

The list of folders is shown, the mail titles of the current folder are shown, the selected mail is not shown, just the roller while one core stays busy.
The Opera javascript console claims one error.

But i can show mails from the mailboxes from the local dovecot IMAP mailboxes.

General server configuration

Operating system: Linux J6868 2.6.32-5-xen-686 #1 SMP Sun Jul 13 02:47:03 UTC 2014 i686
Kernel: 3.10.0-693.2.2.el7.x86_64
CentOS Linux release 7.4.1708 (Core)

Web server: Apache/2.4.6 (CentOS)

Database: mysqld 10.1.28-MariaDB

PHP version: PHP 7.1.10 (cli)

Nextcloud configuration

Nextcloud version: 12.0.3 - 12.0.3.3

Updated from an older Nextcloud/ownCloud or fresh install: 11.0.x

Where did you install Nextcloud from: tar

Are you using encryption: no

Client configuration

Browser: Opera 48.0.2685.39 & Firefox 56.0

Logs

Nextcloud log

Error | PHP | Narrowing occurred during type inference. Please file a bug report on bugs.php.net at /var/www/html/nextcloud/lib/composer/composer/ClassLoader.php#444 | 2017-10-22T20:00:41+0200
-- | -- | -- | --
Error | PHP | Narrowing occurred during type inference. Please file a bug report on bugs.php.net at /var/www/html/nextcloud/lib/composer/composer/ClassLoader.php#444 | 2017-10-22T19:55:46+0200
Error | PHP | Narrowing occurred during type inference. Please file a bug report on bugs.php.net at /var/www/html/nextcloud/lib/composer/composer/ClassLoader.php#444 | 2017-10-22T18:57:55+0200
Info | updater | \OC\Updater::resetLogLevel: Reset log level to Warning(2) | 2017-10-22T18:54:45+0200
Info | updater | \OC\Updater::maintenanceActive: Maintenance mode is kept active

Browser log

core.js?v=5e62c204c9d0686558507be74b7a52c7-19:7 JQMIGRATE: Migrate is installed, version 1.4.0
init.js:25 Starting Mail …
cache.js:47 initializing cache…
js.storage.js:152 Uncaught (in promise) DOMException: Failed to execute 'setItem' on 'Storage': Setting the value of 'messages' exceeded the quota.
at Object._set (https://xxx.at/apps/mail/js/build/build.js?v=5e62c204c9d0686558507be74b7a52c7-19:15687:15)
at Object._callMethod (https://xxx.at/apps/mail/js/build/build.js?v=5e62c204c9d0686558507be74b7a52c7-19:15973:22)
at Object.set (https://xxx.at/apps/mail/js/build/build.js?v=5e62c204c9d0686558507be74b7a52c7-19:15996:30)
at Object.addMessage (https://xxx.at/apps/mail/js/build/build.js?v=5e62c204c9d0686558507be74b7a52c7-19:8644:11)
at https://xxx.at/apps/mail/js/build/build.js?v=5e62c204c9d0686558507be74b7a52c7-19:8884:29
at
js.storage.js:152 Uncaught (in promise) DOMException: Failed to execute 'setItem' on 'Storage': Setting the value of 'messages' exceeded the quota.
at Object._set (https://xxx.at/apps/mail/js/build/build.js?v=5e62c204c9d0686558507be74b7a52c7-19:15687:15)
at Object._callMethod (https://xxx.at/apps/mail/js/build/build.js?v=5e62c204c9d0686558507be74b7a52c7-19:15973:22)
at Object.set (https://xxx.at/apps/mail/js/build/build.js?v=5e62c204c9d0686558507be74b7a52c7-19:15996:30)
at Object.addMessage (https://xxx.at/apps/mail/js/build/build.js?v=5e62c204c9d0686558507be74b7a52c7-19:8644:11)
at https://xxx.at/apps/mail/js/build/build.js?v=5e62c204c9d0686558507be74b7a52c7-19:8884:29
at

js.storage.js:152 Uncaught (in promise) DOMException: Failed to execute 'setItem' on 'Storage': Setting the value of 'messages' exceeded the quota.

I guess that could be the issue. We don't catch that.

@christophKi If you have the chance, check the MessageId. In Firefox you would open the web console with F12 or CTRL-SHIFT-k and watch the list of resources getting loaded, not sure how to see that on Opera.

If the browser gets stuck on a resource like: https:///index.php/apps/mail/accounts/2/folders/AB1CD2EF/messages/123456789 then it's probably the same issue. Most interesting is the last number, which is the message ID. If that is ridiculously large you're seeing the same issue - or at least the same thing triggers your issue.

By the way, Opera shows the error at the same place as Chrome: js.storage.js:152 Uncaught (in promise) RangeError: Invalid string length at JSON.stringify () at Object._set (js.storage.js:152) [...] it's just packing the information differently, so it's most likely the same issue.

Yes :) it's the same. Thx

This is from the Firefox log with a large message ID where it gets stuck:
index.php/apps/mail/accounts/1/folders/SU5CT1g%3D/messages/32627360

From an other mailbox where i can show the messages, with shorter ID:
index.php/apps/mail/accounts/4/folders/SU5CT1g=/messages/1329

Best regards

Ah, as much as I know, opera used the same engine as chrome.

I believe that the message ID is broken, or at least the way it is interpreted. Stepping through the code in question I noticed that the app generates an array with MessageID entries to store the messages for the folder. When trying to add the message to the cache, the localStorage gets exhausted by trying to add an empty array with over 600.000.000 indices. Looking into the data, the mail body is there though, so it's not like the server returned random data.

I have not yet found the place where the MessageID comes from. It also does not seem to correlate with the number of messages in the folder. What I saw so far: 106 Messages in Folder - last message ID 95, 295 - 280, 192 - 627182270, 408 - 627198350

I found a workaround. Since the Message ID is just used as a hash token for the cache and the numbers are consecutive, I decided to just truncate them down to 1024. This lets me read my messages again. However this will mess up the cache on folders with more than 1024 messages - which is why I'm reluctant to call it a real fix.

The proper way would be to align the MessageID with the actual number of messages in the folder. On the other hand I feel like this is 'good enough' as I'm not sure how many people will actually have folders with more than 1024 messages.

getMessagePath: function(account, folder, messageId) {
return [this.getFolderPath(account, folder), (messageId%1024).toString()].join('.');
}

@christophKi I'm not sure how much control you have over your installation, otherwise I would send you the build.js to replace your local version so you can at least give it a spin. That should be enough to have my patch - it's also built against the current release (0.7.3), not the head as that doesn't work for me either.

You could also just edit mail/js/build/build.js, find the getMessagePath() function and edit it there. Should be line 8576. Tested that by incrementing the modulo to 2028

Still happens with 0.7.7... modulo workaround still works.

One thought on this: to have a clean solution I believe it would make most sense to get the lowest MessageID of the current folder and take that as base offset value. However that would mean that getMessagePath() needs an easy way to retrieve that number. Also I'm not sure if 'getting the lowest MessageID' is a feasible task at all. Right now I'm using a Modulo of '10240' as a workaround which has not yet shown any issues and has no impact on performance.

Otherwise I'm curious if me and @christophKi really the only ones seeing this problem.

Jup, today I updated to nextcloud 12.0.5 and mail 0.7.9. Sill the same problem.

greetings

Was this page helpful?
0 / 5 - 0 ratings

Related issues

jancborchardt picture jancborchardt  Â·  4Comments

benks-io picture benks-io  Â·  4Comments

MariusBluem picture MariusBluem  Â·  3Comments

Valdnet picture Valdnet  Â·  3Comments

fsedarkalex picture fsedarkalex  Â·  5Comments