maemo.org Bugzilla – Bug 11139
Long delays in email interface
Last modified: 2010-10-26 17:44:44 UTC
You need to log in before you can comment on or make changes to this bug.
SOFTWARE VERSION:unknown, but using N900 with pr1.2 (Settings > General > About product) EXACT STEPS LEADING TO PROBLEM: (Explain in detail what you do (e.g. tap on OK) and what you see (e.g. message Connection Failed appears)) 1. Click on email icon 2. when list of mail accounts comes up, click on Mail for Exchange 3. There is a very long delay (sometimes a minute or more while waiting for the list of emails to appear. 4. When list of emails comes up, click on an email. It highlights in blue, and then there is another long delay waiting for the email to open 5. The email finally opens. Click the left and right arrows to navigate to other emails. This happens without delay. Also: Click on the yellow email alert and there is a long delay before the email opens. EXPECTED OUTCOME: The list appears quickly or the email opens quickly ACTUAL OUTCOME: Long delays to get list of emails or individual emails REPRODUCIBILITY: ALWAYS (always, less than 1/10, 5/10, 9/10) EXTRA SOFTWARE INSTALLED: unsure how to generate the list or what is relevant. Please advise if this is necessary. OTHER COMMENTS: A few (possibly related) items: If I run dbus-monitor, during the delay time I see several of these: method call sender=:1.71 -> dest=org.freedesktop.Notifications serial=99757 path=/org/freedesktop/Notifications; interface=org.freedesktop.Notifications; member=CloseNotification uint32 163 signal sender=:1.31 -> dest=(null destination) serial=99227 path=/org/freedesktop/Notifications; interface=org.freedesktop.Notifications; member=NotificationClosed uint32 163 method call sender=:1.31 -> dest=com.nokia.HildonSVNotificationDaemon serial=99228 path=/com/nokia/HildonSVNotificationDaemon; interface=com.nokia.HildonSVNotificationDaemon; member=StopEvent int32 165 method return sender=:1.31 -> dest=:1.71 reply_serial=99757 method call sender=:1.71 -> dest=org.freedesktop.Notifications serial=99758 path=/org/freedesktop/Notifications; interface=org.freedesktop.Notifications; member=CloseNotification uint32 162 signal sender=:1.31 -> dest=(null destination) serial=99230 path=/org/freedesktop/Notifications; interface=org.freedesktop.Notifications; member=NotificationClosed uint32 162 and then lots of these: error sender=:1.31 -> dest=:1.71 error_name=org.freedesktop.DBus.GLib.ErrorError reply_serial=99776 string "Method invoked for CloseNotification returned FALSE but did not set error" method call sender=:1.71 -> dest=org.freedesktop.Notifications serial=99777 path=/org/freedesktop/Notifications; interface=org.freedesktop.Notifications; member=CloseNotification uint32 142 error sender=:1.31 -> dest=:1.71 error_name=org.freedesktop.DBus.GLib.ErrorError reply_serial=99777 string "Method invoked for CloseNotification returned FALSE but did not set error" method call sender=:1.71 -> dest=org.freedesktop.Notifications serial=99778 path=/org/freedesktop/Notifications; interface=org.freedesktop.Notifications; member=CloseNotification uint32 141 error sender=:1.31 -> dest=:1.71 error_name=org.freedesktop.DBus.GLib.ErrorError reply_serial=99778 string "Method invoked for CloseNotification returned FALSE but did not set error" method call sender=:1.71 -> dest=org.freedesktop.Notifications serial=99779 path=/org/freedesktop/Notifications; interface=org.freedesktop.Notifications; member=CloseNotification uint32 140 error sender=:1.31 -> dest=:1.71 error_name=org.freedesktop.DBus.GLib.ErrorError reply_serial=99779 string "Method invoked for CloseNotification returned FALSE but did not set error" method call sender=:1.71 -> dest=org.freedesktop.Notifications serial=99780 path=/org/freedesktop/Notifications; interface=org.freedesktop.Notifications; member=CloseNotification uint32 139 error sender=:1.31 -> dest=:1.71 error_name=org.freedesktop.DBus.GLib.ErrorError reply_serial=99780 string "Method invoked for CloseNotification returned FALSE but did not set error" method call sender=:1.71 -> dest=org.freedesktop.Notifications serial=99781 path=/org/freedesktop/Notifications; interface=org.freedesktop.Notifications; member=CloseNotification uint32 138 The file /var/lib/gconf/apps/modest/accounts/Mail@32@for@32@ExchangeID/%gconf.xml is growing frequently, and it appears to be the <li> nodes in the notification ids. A sample: <?xml version="1.0"?> <gconf> <entry name="notification_ids" mtime="1281391489" type="list" ltype="int"> <li type="int" value="163"/> <li type="int" value="162"/> <li type="int" value="160"/> <li type="int" value="159"/> <li type="int" value="158"/> <li type="int" value="157"/> <li type="int" value="156"/> <li type="int" value="155"/> <li type="int" value="154"/> <li type="int" value="153"/> <li type="int" value="152"/> <li type="int" value="151"/> <li type="int" value="150"/> <li type="int" value="149"/> <li type="int" value="148"/> This is making email unusable. I would like to find a solution short of re-flashing the device--especially because a reflash would not help others avoid the bug or conflict responsible for this. User-Agent: Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9.2.8) Gecko/20100723 Ubuntu/10.04 (lucid) Firefox/3.6.8
Similar behaviour here - I have few if any emails in my Nokia Messaging device inbox, yet navigating from the account selection screen to the folder list can take 20-30 seconds, and opening the inbox takes another 20-30 seconds (even if it contains only a single email) and opening an email (any email) can take 20-30 seconds. Modest is awful, really. With each passing day it's becoming less and less practical to read emails on the device - when I do have an important email to read I make sure I have plenty of time to do so.
*** Bug 11162 has been marked as a duplicate of this bug. ***
*** This bug has been confirmed by popular vote. ***
This happen after last OS update for n900.
Regarding comment #4: my issues started some time after I installed PR1.2, but if the issue is related to the continually increasing number of dbus notification messages being sent, then it may have taken some time for the number of messages to create delays which were noticeable. One more note: I can put the phone into offline mode and the delays are the same. That suggests that the issue is not related to communication between modest and the email server.
In addition to the symptoms described, Modest often locks up on me when attempting to display HTML email. A handful of modest pictures (which download in a few seconds in the browser) will make Modest seize up for so long that the OS offers to kill it. An example of this is ebuyer emails (http://www.ebuyer.com/eblast), but I've had others with worse delay-to-size ratio.
I deleted the account from the phone and recreated it. After a few minutes of sync, the account was restored with nothing gone, and the delays were no longer in place. Whether it was related or not, the gconf file mentioned previously no longer contained a node for entry name="notification_ids", which was continually increasing in size before. I will check to see if, over time, this starts to build up again and if that corresponds to increasing delays. In any case, if anyone else is experiencing this problem, I would suggest as a workaround that you remove the account and then recreate it. Much less drastic than reflashing the phone, and it seems to eliminate the problem (for now). I will report here if the delays begin to creep up again.
After recreating the account, the notification ids list immediately started increasing again, and the size of the list was directly related to the number of dbus calls that were seen when the email was opening. Previously, I could not delete the list from the gconf file because it simply reappeared shortly after I saved the gconf file. I was able to remove it, though, by killing the two instances of modest (with pids found through a "ps -ef | grep modest", updating the file, then killing the new pids found with another ps, then rebooting for good measure. Not sure if all of that was necessary (I'm sure there is some simpler combination that will keep the file from being rewritten after the deletes), but the deleted lines in the file stayed deleted, so I think this is a useable workaround short of removing and restoring the account. When the list builds up enough to cause noticeable delays (I had thousands of entries in this list, causing thousands of dbus calls on every email operation), I will try deleting like this again and see if that clears it up. None of this explains why the problem is happening, but at least it helps me get my email back to usability when it gets bad.
(In reply to comment #6) > In addition to the symptoms described Please file a separate report & attach a testcase without confidential data.
Just a quick update: after a week the delay was becoming noticeable again. The number of entries in the notification_ids node climbed up above 500. I edited the gconf file, removed the entries in the notification_ids node, and immediately rebooted and the nodes stayed deleted. The delay is gone again (for now). These notification ids building up are definitely the culprit for the delay. The question now is why the notification ids are building up without being deleted. I have a theory surrounding the spam filtering on my exchange server (modest usually gives me an email notification BEFORE it gets moved out of the inbox into junk mail) and I will try to test this theory and report back here.
Following up on the last comment, I observed the following by watching the gconf file: When an email comes in, a notification is delivered (the yellow alert) and an li node is added to the notification node in the gconf file. When the notification is cleared, the li node remains. When the email is read, the li node remains. When the email is deleted, the li node remains. Even if I wait a while and check again, the li node remains. I have a gmail account as well. I rarely use it and don't get many emails at all on it. It is showing the same behavior as the MFE account: the li nodes are added but never removed. When I get spam on my MFE account, I get a notification (modest sees it in the inbox and alerts me before my mail host moves it to the junk folder). I get mulitple li nodes for spam--the first one when the original message arrives and additional ones when the mail is moved to the junk folder. I have been getting a high volume of spam lately, as well as a large number of automated email messages from systems at work, so the list was able to build up quickly. I don't know whether others are seeing this behavior, or whether I have some setting that is causing these notification_ids (and the related dbus messages that go with them) to build up. I know there are a few others watching this thread, so I would be interested to know if they are seeing the notification_ids node in the gconf file (see the original bug description for the file location) similarly growing.
> I would be interested to know if they are seeing the notification_ids > node in the gconf file Yep, I have 1382 "<li>" nodes at the moment, some of which are duplicated more than once, eg: <li type="int" value="228"/> <li type="int" value="228"/> <li type="int" value="228"/> Each new email that arrives in my inbox creates one new "<li>" node. I'm using Nokia Messaging accessing a single Google Mail account. It's frustrating and saddening to see you put in all this effort diagnosing what is almost certainly an easy to reproduce flaw, only to see it being ignored by Nokia and in particular the Modest developers. I can only hope the QT Messaging Framework[1] will finally give Nokia owners the email client they deserve, but this is of precious little comfort for existing N900/Maemo owners that are saddled with the amateur hour rubbish which is Modest. 1. http://moimart.tumblr.com/post/898095695/qt-messaging-fw-is-in-meego
I should also add that each new email is generating a new <li> node with a new sequential number, the last number generated is 230. However I there are <li> nodes in the gconf file that already have higher sequential numbers (340, 341, 342 etc.) that are "further down" the gconf file, eg. <li type="int" value="2"/> <li type="int" value="1"/> <li type="int" value="341"/> <li type="int" value="340"/> <li type="int" value="339"/> I have deleted my Nokia Messaging account in the past, I've also attempted a restore from backup on two previous occasions (PR1.1, PR1.2, both failed due to Nokia Messaing account details not restoring properly from backups) which may have "corrupted" the gconf file. Irrespective of the backups however, there seems little need to keep all these old <li> nodes present in the file - my inbox currently contains 4 emails. The performance of Modest on the device is now so bad that I don't even bother reading emails unless I'm expecting to receive an important email. Changing severity to Critical, because Modest is verging on the unusable.
Neil: Try deleting the <li> nodes, saving the file, and then immediately rebooting. After reboot, check the file to see that the <li> nodes are still gone (they can get rewritten by modest if you don't shut down). Then test your email to see if the delays are gone. This is by no means a solution, but it should make your modest useable again. I have looked through the modest code and I can find where these notification_id nodes are being created, but I can't find any code that removes them. I agree that this is frustrating, but I am still trying to be nice to the developers and Nokia people, who I would love to hear from in some fashion.
Created an attachment (id=3077) [details] gconf file that results in poor performance Hi Richard, I can confirm that deleting all the <li> nodes (actually, I left one as follows: <entry name="notification_ids" mtime="1283880647" type="list" ltype="int"> <li type="int" value="1"/> </entry> and then rebooting *DOES* resolve the performance issue - the next email I received created the following node: <li type="int" value="2"/> and performance was more than acceptable (back to normal, one could say). However as you point out, this isn't really an acceptable solution - it just proves the point or at least identifies where problem is occurring, it's now up to Nokia to provide a fix, hopefully there is still time for PR1.3 but chances are the lack of any developer input on this bug means we have missed that boat. Unfortunately the lack of Nokia developer involvement in Bugzilla has been a major issue since it's inception in 2005 (see bug #630 for more details) and it's unlikely this bug will ever be fixed on Maemo. I am attaching my original gconf file to this bug should any Nokia or Modest developer care to show the slightest bit of interest in their product.
@Richard: Thanks for your efforts on this bug, btw.
It's interesting to note that despite only having two <li> nodes in the gconf file, I can still any existing emails in my inbox without a problem (I now have 7 emails in my inbox, and only two <li> node entries). Switching between views in Modest is now fast (ie. selecting account, opening inbox, opening emails etc.) when previously these same actions took many many seconds suggesting that the gconf file is being parsed at every opportunity. Not only is this grossly inefficient, it's compounded by the fact that old entries are never removed. Having deleted the <li> nodes, when a new email comes in the token that floats across the top of the screen now appears more quickly and is less intrusive - previously, the current application would freeze as the device vibrated to signify a new email, then after a short delay the token would glide across the top of the screen and then eventually the current application would begin to respond again. Obviously this notification process is also parsing the gconf file and bringing the device to it's knees...
I don't think it is the parsing of the gconf file, but the dbus calls to CloseNotification. This call closes the yellow box on the task manager page. The id is not related to how many emails you have, but how many notifications have opened since you started up the device. The call is made when you open a folder or email so that the notifications are cleared. You can test it out yourself if you like if you have mdbus2 installed (I'm sure you can use other dbus tools, also). Wait until you have emails waiting and then look at the gconf file to see what is at the top of the list (those appear to be the newest ones). You will see some notification id numbers. Pick the first one (for our example, we'll use the number 6). From a command line type the following: mdbus2 org.freedesktop.Notifications /org/freedesktop/Notifications org.freedesktop.Notifications.CloseNotification 6 You should see the notification disappear (or, if there are multiple notifications, you will see the number decrement). If you look at the dbus calls available on notify, you will see that there is no way to obtain a list of open notifications. So modest is keeping track of ALL of the notifications it opens and just sending close messages for all of them when you open the email. But after it sends the close messages, it is apparently NOT clearing out the list of messages. This appears to be the bug. If, after sending the close messages, modest wiped out its list of notification_ids, the list would never build up very big and and the closenotification calls would not delay opening except in very rare cases. The modest website lists some mail lists and an irc channel for communication. I am going to look at those and see if there is any info on fixes or releases, etc. It should be somewhat simple to install an updated version of modest outside of the pr1.3 train...whether doing so a good idea is another question entirely.
It looks like this problem may be fixed in this commit: http://gitorious.org/modest/modest/commit/cbfb96c950c42963ae971cc6a2355c8897f7bf28 which appears to be in version 3.3. The version in our repositories (or, at least, installed on my device) in 3.2.13. I am looking into possibility of upgrading (I know its possible...I just want to figure out how much trouble it is an whether it is worth it.) This will probably require some scratchbox testing before I mess with the phone, but if I get to work on it soon I will report here.
> I don't think it is the parsing of the gconf file, You're right, it's the dbus spamming and not parsing that is causing the delays (although Modest does seem to be parsing or at least iterating the list with each action, necessary in order for it to spam dbus so successfully). I've now run dbus-monitor and I see the same multitude of dbus notifications as you have seen, but now much reduced thanks to purging the gconf file of <li> nodes. As you have discovered Modest is firing out these dbus calls when navigating between any action - whether that be navigating from the Nokia Messaging client selection screen to the individual account selection screen, from there to the folder selection screen, when viewing the inbox or even reading an email - every time I change a view there follows a mass of these dbus notification calls, one for each <li> node. Since I was up to 1382 of these <li> nodes it's no wonder my device was performing like cr@p! Modest is basically spamming dbus every time the user does something - anything - and since these dbus calls are sent once for each <li> node it's a horrifically inefficient design decision. The mass of dbus notifications also seem to serve no real purpose once the user is actively using Modest - if the intention is to close the new mail notification icon then logically it this icon must already have been closed if the user is navigating within Modest... so why are the dbus calls even necessary? Fixing the notification system so it cleans up the gconf file as each notification is accessed is one part of the problem, but fixing Modest so that it doesn't spam dbus unnecessarily would also be a very worthwhile improvement (although fixing the former would almost certainly resolve - or at least hide - the latter problem). > It looks like this problem may be fixed in this commit: Great news, let's hope it's not too late for PR1.3, assuming there is a PR1.3. Hopefully Andre can give us an update in the few days, I pinged him on IRC earlier this evening to see if this issue could get some official attention/response as you have done so much of the donkey work identifying the underlying issue. Thanks again for that.
(In reply to comment #19) > It looks like this problem may be fixed in this commit: http://gitorious.org > /modest/modest/commit/cbfb96c950c42963ae971cc6a2355c8897f7bf28 (int-161187) Would be great to get a confirmation if that commit really fixes it. Fix was included in the internal non-public image 2010.23-4 (modest 3.4.0+0m5) and will definitely be part of the next public update for Maemo5.
Internal comment: "This fix is available in the next public release. And yes, it was the reason for slow folder opening problem."
Thanks Andre, Richard.
The problem reported here should be fixed in the update that was released today for public: The Maemo5 update version 20.2010.36-2 (also called "PR1.3" sometimes). Please leave a comment if the problem is not fixed for you in this update version.
I can confirm it works, but note that it seems you need to A) Get a notification B) Tap on it (so as to clear it) .. in order to invoke "the fix" and clear all the notifications. After that, delays are gone.
Is this the way to remove those notification IDs? at least it looks a bit faster for a in `gconftool --all-dirs /apps/modest/accounts`; do gconftool -s --type list --list-type int '[]' $a/notification_ids ; done