Closed Bug 687430 Opened 13 years ago Closed 13 years ago

Feeds of an account stopped automatically updating, checking manually works only for single feeds, not whole account

Categories

(MailNews Core :: Feed Reader, defect)

Product:
MailNews Core
Component:
Feed Reader
Platform:
x86
Windows XP
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(thunderbird9+ fixed, thunderbird10+ fixed)

Status:
RESOLVED FIXED
Milestone:
Thunderbird 11.0
Tracking Flags:
Tracking Status
thunderbird9 + fixed
thunderbird10 + fixed

People

(Reporter: aryx, Assigned: Bienvenu)

References

Details

(Keywords: regression, testcase)

Attachments

(5 files)

files of a problematic rss account
94.47 KB, application/octet-stream
Details
Bill B. non-working feeditems.rdf file
2.53 MB, application/octet-stream
Details
Bill B. non-working feeds.rdf file
45.55 KB, application/octet-stream
Details
Bill B. exported OPML file from TB having 53 feeds.
4.49 KB, text/plain
Details
stop db's from getting out of date
853 bytes, patch
neil
: review+
standard8
: approval-comm-aurora+
Details | Diff | Splinter Review 
Mozilla/5.0 (Windows NT 5.1; rv:6.0.2) Gecko/20110902 Thunderbird/6.0.2

The feeds of two rss accounts stopped automatically updating, checking manually (with context menu) works only for single feeds, not the whole account.

This problems only seems to apply to two accounts which are expanded in the folder pane, three other accounts which are collapsed and move theirs messages by mails folders to other folders seem to work fine.

The status bar even doesn't show any attempts to update the feeds if there is no success.
i can confirm this.  the problem seems to be that any folder which needs to rebuild the .msf db will fail to auto update.  manually selecting such a folder, Properties->Repair Folder, waiting for completion/statusbar message, and then Get New Messages, works for me as a workaround.

i'm reasonably certain this is a Tb5 regression at least, rather than Tb6.

note that there may be other as yet undiscovered reasons for feed update failure; for example bug 682606 was recently fixed, but was a bit more of a rare/esoteric case.
I can confirm this too, and also that checking the account manually using the context menu (as mentioned in the original report) gets Thunderbird to download new messages.  However, using the Get Mail button, which I thought would do the same, doesn't download anything.

I also tried repairing the folder as discussed in the Comment 1.  When I did this I noticed that "Thunderbird Mail" page (with the Feeds, Accounts and Advanced Features links) popped up.  I see this regularly when I select a couple of feeds that have still been updating regularly, as if Thunderbird was automatically doing the repair, so maybe the folders are getting corrupted fairly regularly by some process.
Still not working on 7.0.1.  I can confirm that the feed folders are regularly getting corrupted by normal operations.  Compacting all folders followed by Get Mail will generally cause some feeds to update.  However, many popular feeds (Bad Astronomy, eWeek, Dealcatcher) are now not updating at all, even after Repair Folder followed by Get Messages for the individual feed.

I also tried closing TB, deleting all the msf files, and re-starting, didn't help.

 Something is very badly broken.
Can we get a more precise regression range guys ?
Keywords: regression, regressionwindow-wanted
(In reply to Ludovic Hirlimann [:Usul] from comment #4)

> Can we get a more precise regression range guys ?

My best guess, based on "holes" in feed records, is that this started around 4 July 2011.  So whatever version came out then.  I normally update within a day of the notification by Thunderbird.
I've done some testing, and for me at least this does not appear to be an inherent fault in TB7, but more likely a corruption of the news feeds control files somewhere in the update from previous versions.

Steps to check this:

Closed TB and renamed the Feeds folder.

Opened TB (which now showed no feeds) and added the eWeek feed (which would not update under any circumstances after I installed TB 7.0).  The feed downloaded new messages immediately on setup.

Reverted to the old Feeds folder and eWeek messages would not download.

I've attached feeditems.msf and feeds.rdf from the non-working set for possible analysis.
I tried exporting my feeds, closing TB, renaming the Feeds folder, then importing.  This resulted in my original 53 feeds becoming only 21, the rest being lost.

I've attached the OPML file for comparison with the feeds files previously attached.
Investigating further, I compared the new feeds.rdf file with the old one.  In the new file, one line for each feed looks like this:

<fz:destFolder RDF:resource="mailbox://nobody@Feeds/... 

In the old file, some lines look like that, while others are:

<fz:destFolder RDF:resource="mailbox://nobody@News%20%26%20Blogs/... 

The feeds with this format are the ones not updating.

I edited the feeds.rdf file to change all the lines to the "nobody@Feeds" format, and the problem groups then started updating correctly.
Keywords: testcase
to pick up the baton here, i think the problem is this:
1. feeds that are an <rdf:li resource> but whose <fz:feed> entry points to a nonexistent <fz:destFolder> value, will show up in Subscriptions as a non container folder.  if the destFolder is valid, the folder will contain the feed item child (as a feed icon).
2. the invalid destFolder items are the ones getting corrupted/not updated.  this can be seen, if there are any unread items in such a folder, by hovering to get a preview tooltip.  this will show a tiny broken tooltip and throw:
Error: Component returned failure code: 0x80550005 [nsIMsgFolder.msgDatabase] = <unknown>
Source file: chrome://messenger/content/mailWidgets.xml
Line: 2150
which perhaps has to do with changes in Bug 473458.
3. it's unclear if changes in Bug 471932 were mostly cosmetic (or attempted to fix folder move/rename issues).  however, a move (dnd in folderpane) does not update the item's destFolder to reflect the new folder location (though Subscriptions does show the item in a like named folder under the new subfolder).

further evidence is that i have a folder with 2 child feed items, one the main feed and the second its comments.  the first has an invalid destFolder, while the second was created after the folder was set up, and thus does have a correct destFolder.  corruption (as detected by the broken tooltip) results when the first updates, and seems fixed when the second updates.

so the question is whether Bug 471932 broke or didn't fix folder moves/renames/deletes in the feeds.rdf file.  and whether no longer passing an msgWindow has anything to do with error recovery, ie if a moved folder rename (invalid destFolder error) was masked until Bug 473458.

copying cited bugs' authors for ideas.
alta88: Are you sure that this is caused either by bug 471932 or bug 473458? Both have been fixed in early 2009, so this regression should have surfaced during Thunderbird 3.1.* usage.

I tried with Mozilla/5.0 (Windows NT 5.1; rv:9.0) Gecko/20111115 Thunderbird/9.0 and discovered the following:
Having set the focus in the folder pane to a subfolder of a feed account and right-clicking onto the account name and choosing "Get messages" fixes the issue, but only for the currently selected folder.
A kill rdf / js folder pane regression in terms of a regession fix for bug 414038 causing this regression?
no, not sure, those were just some suspects.

the problem is this code,
http://mxr.mozilla.org/comm-central/source/mailnews/local/src/nsRssIncomingServer.cpp#187
does not do anything when it can't get the .msf database and just silently ignores the update attempt.  as it turns out, the .msf database is getting physically deleted from disk and thus there is no folder.msgDatabase property (why preview tooltips also throw).  an action that triggers a codepath that rebuilds it is thus needed, like selecting the folder.

hopefully someone with better knowledge of why a msgDatabase would be deleted can chime in.
note that is some cases folder.msgDatabase is not there and the file is also not on disk, and in others it is on disk but apparently corrupt.  i've noticed both cases.
My feed db's are getting out of date regularly. Diagnostics indicate this is because the timestamp stored in the db is very different from actual timestamp on the corresponding folder (> 60 minutes) which implies that we're adding messages to the feed folder without updating the db. I'm not sure where this used to happen, or indeed, if it's stopped happening completely. 

I'm also unconvinced that the original report is the same as alta88's last comment (i.e., there may be two separate problems).
Here's the stack trace where we write the timestamp:

 	xul.dll!nsMailDatabase::SetSummaryValid(bool valid=true)  Line 495	C++
 	xul.dll!nsMsgMailboxParser::UpdateDBFolderInfo(nsIMsgDatabase * mailDB=0x19922018)  Line 417	C++
 	xul.dll!nsMsgMailboxParser::UpdateDBFolderInfo()  Line 411	C++
 	xul.dll!nsParseNewMailState::DoneParsingFolder(unsigned int status=0x00000000)  Line 1796	C++
 	xul.dll!nsMsgMailboxParser::OnStopRequest(nsIRequest * request=0x00000000, nsISupports * ctxt=0x00000000, unsigned int aStatus=0x00000000)  Line 200	C++
>	xul.dll!nsMsgLocalMailFolder::AddMessageBatch(unsigned int aMessageCount=0x00000001, const char * * aMessages=0x004352ec)  Line 3922	C++
 	xul.dll!nsMsgLocalMailFolder::AddMessage(const char * aMessage=0x1e5270b8)  Line 3869	C++

so it looks like normally we're doing the right thing. I'm not sure where we're going wrong. It's possible that if we shut down in the middle of updating a feed, we might end up with messages added to a feed folder without the feed folder db getting updated correctly. This may have started happening to me when I changed my update interval to 100 minutes from 60, which would mean that if an update were aborted, my timestamp would be out of date. But, we mark the db valid after every message gets written, so I don't see how shutting down could interrupt the UI thread like that.
though, my feeds trash folder is also out of date, which kinda rules out the feed updating as being the issue, or at least, the only issue.
The feed files I attached to this show now missing files but updates being sometimes more than a month old. Furthermore, most of my feeds accounts check less often than 60 minutes, but only some broke.
But I noticed something which distinguishes the feeds accounts where updating broke from the other ones: They had been expanded (folders of account had been visible) while the other feeds accounts had always been collapsed (they are moved with a folder somewhere else). So what could break this? Is there a difference how shown and hidden folders with "new" messages get downgraded to "unread"? This is something happening either on startup or shutdown of Thunderbird and I hadn't interacted with some feed folders on the day they broke.
(In reply to Archaeopteryx [:aryx] from comment #19)

So what could break
> this? Is there a difference how shown and hidden folders with "new" messages
> get downgraded to "unread"? This is something happening either on startup or
> shutdown of Thunderbird and I hadn't interacted with some feed folders on
> the day they broke.
No. And that wouldn't explain why db's are getting out of date. I don't have any hierarchies in my feeds, but I can try having the account collapsed when I start up, and see if db's get out of date.
i found an old bug 437430 so this apparently has been happening for a while.  by 'this', i mean folder.msgDatabase isn't there when asked for, and it isn't being reparsed outside of active user folder selection.

perhaps the place to start is to figure out why it goes away. it's not null either, and it gets nulled in a lot of places. the property has either been deleted or else the folder object has been recreated without it.  

gFolderTreeView has a map of folders which probably gets recreated under some conditions.  it could be legitimate that the folder object doesn't have an msgDatabase and that other account types auto create it on demand.

the feed code (js) only touches (closes) msgDb in a folder move/delete situation, not normal updating.

anecdotally, on certain feeds msgDatabase is gone on every update cycle (60m usually).  it seems only to be feeds that are in a subfolder that suffer this, and the few that are directly under the account folder do not.
I see bug 437430 and Thunderbird rebuilts the feeditems.rdf and feeds.rdf. So while rebuilding, some feeds don't get added - do corrupt feed .msf files or extensionless files cause this?
Another thing I recognized, but maybe coincidence: In the subscription dialog, I can that the feed of every third folder is missing: The first one I have unsubscribed, so I doesn't contain anymore subscribed feeds, only older items, but folder 4, 7, 10 and 13 have lost theirs feeds, while 3, 5, 6, 8, 9, 11 and 12 have them (1 has also been unsubscribed some time ago).
(In reply to Archaeopteryx [:aryx] from comment #22)

the issue isn't feeds.rdf (if it doesn't exist you won't have any feeds in Subscribe, just the existing folders) or feeditems.rdf (merely a store of 'current' messages in a feed to avoid dupes, i believe).  if you remove feeds.rdf Tb creates an empty file.  there are issues with cleaning up both these stores, but they aren't showstoppers.

the issue is silently recreating a feed's .msf msgDatabase file on demand if not there, and why it gets bad/not there.  this basically is a showstopper.
It's pretty clear to me that the issue is the timestamp in the db doesn't correspond to the timestamp of the folder. You could try using the config editor to set mail.db_timestamp_leeway to a very large (32 bit) number like 10000000 - it's in seconds. See if the bug still happens once you do that.

If the rss code wants to regenerate db's that are out of date, in can do so by calling nsIMsgLocalMailFolder:: getDatabaseWithReparse(in nsIUrlListener aReparseUrlListener, in nsIMsgWindow aMsgWindow)

when it's told the db is out of date.
(In reply to David :Bienvenu from comment #24)

i can try that, but it seems sort of like not a real solution..

i've read the code a bit and it's clear in RssIncomingServer how updates are bypassed if GetSummaryValid timestamp check fails.  but it's not clear the codepath or reason that also removes the msgDatabase property so other accesses fail, like in bug 437430 (tooltips) eg.

it's also not clear the reasoning for the timestamp sanity check.  if it is a legit check, then probably better to figure out why the out of sync happens.  otherwise, the regen bit should be added to RssIncomingServer update, no?

(i went directly from assembler to javascript so am not the right person to do cpp patches)..
(In reply to alta88 from comment #25)
> (In reply to David :Bienvenu from comment #24)
> 
> i can try that, but it seems sort of like not a real solution..

I suggested it for diagnostic purposes, not as any kind of solution.
(In reply to David :Bienvenu from comment #24)

> You could try using the config
> editor to set mail.db_timestamp_leeway to a very large (32 bit) number like
> 10000000 - it's in seconds. See if the bug still happens once you do that.

I changed mail.db_timestamp_leeway from 4,000 to 4,000,000 and, after restarting Thunderbird, the RSS feeds now seem to be updating correctly.  So the problem does seem to be the timestamps.
i changed the pref to 217000sec which is just a bit more than the 60min refresh for the feed account, selected all feeds, and have not had a single failure (broken tooltip, and presumably updates all succeed) since, on any of 30+ feeds.
spoke too soon.  several feeds had broken tooltips and stopped updating this am.

david, does nsRssIncomingServer::GetNewMail need to do that check simply to get the feedUrl property?  since the called code can do it and even has a nice fixup function to get the folder's feed urls from the feeds.rdf database, which should be the primary source anyway.

like this:

--- a/mailnews/local/src/nsRssIncomingServer.cpp
+++ b/mailnews/local/src/nsRssIncomingServer.cpp
@@ -200,27 +200,7 @@
   nsresult rv;
   nsCOMPtr <nsINewsBlogFeedDownloader> rssDownloader = do_GetService("@mozilla.org/newsblog-feed-downloader;1", &rv);
   NS_ENSURE_SUCCESS(rv, rv);
-  rv = aFolder->GetMsgDatabase(getter_AddRefs(db));
-  if (NS_SUCCEEDED(rv) && db)
-  {
-    rv = db->GetSummaryValid(&valid);
-    NS_ASSERTION(valid, "db is invalid");
-    if (valid)
-    {
-      nsCOMPtr <nsIDBFolderInfo> folderInfo;
-      rv = db->GetDBFolderInfo(getter_AddRefs(folderInfo));
-      if (folderInfo)
-      {
-        nsCString url;
-        nsString folderName;
-        aFolder->GetName(folderName);
-        folderInfo->GetCharProperty("feedUrl", url);
-
-        rv = rssDownloader->DownloadFeed(url.get(),
-                                         aFolder, PR_FALSE, folderName.get(), aUrlListener, aMsgWindow);
-      }
-    }
-  }
+  rssDownloader->DownloadFeed(nsnull, aFolder, nsnull, nsnull, aUrlListener, aMsgWindow);
   return NS_OK;
 }
I think this will help fix db's from getting out of date. I'm running with it now.
Assignee: nobody → dbienvenu
(In reply to alta88 from comment #30)

> david, does nsRssIncomingServer::GetNewMail need to do that check simply to
> get the feedUrl property?  
In theory, you should be able to add rss messages to the folders with an out of date db, as long as you don't need the information stored in the db...I think that's what you were asking. The next time the user clicks on the folder, the db will get regenerated.
the only access in the feed code to msgDatabase is to retrieve the feedUrl property, which itself is a convenience for the Subscribe dialog, and built based on items in feeds.rdf anyway.

so in fact we don't need to use the .msf db at all, it's too brittle and needs to be surrounded by try catch (bug 705504) etc.  this is also the reason for endless "verifying feed", a failure to get msgDatabase.  clicking the folder isn't the right solution for async updating.

i can submit a patch to switch storing the property via folder.setStringProperty and be done with the msgDatabase completely.
Attachment #577337 - Flags: review?(neil)
(In reply to alta88 from comment #33)
> i can submit a patch to switch storing the property via
> folder.setStringProperty and be done with the msgDatabase completely.
That's not 100% true because setStringProperty uses the database too.
(In reply to neil@parkwaycc.co.uk from comment #34)
> (In reply to alta88 from comment #33)
> > i can submit a patch to switch storing the property via
> > folder.setStringProperty and be done with the msgDatabase completely.
> That's not 100% true because setStringProperty uses the database too.

actually, folder.setStringProperty will store in panacea.dat and does not in fact need to access the big point of failure here (and elsewhere), which is folder.msgDatabase.  it is folder.msgDatabase.dbFolderInfo.setCharProperty, which stores in the folder's .msf file.

for example, bringing up the Subscribe dialog without having clicked the folder to make sure the msgDatabase is rebuilt will not create msgDatabse (if it's not there) and thus the folder's feeds won't be shown there.  try it by deleting a feed's .msf file.

so the bigger picture solution is to get rid of msgDatabase accesses.
(In reply to alta88 from comment #30)

> spoke too soon.  several feeds had broken tooltips and stopped updating this
> am.

All my feeds are still updating as far as I can tell (some only get new content weekly) so I'm not seeing this.

Are you sure that your feeds didn't stop updating because there was no content for a number of days due to the US Thanksgiving holiday?  You only set mail.db_timestamp_leeway to around 60 hours, so if there were no updates from Thursday to Sunday this may have caused the problem.  As I've got mail.db_timestamp_leeway set to over 1,000 hours that would explain why my feeds are still updating.

Thanks too to David for your work on this!
(In reply to alta88 from comment #35)
> folder.setStringProperty will store in panacea.dat and does not in fact need to
> access the big point of failure here (and elsewhere), which is folder.msgDatabase.
It stores it in both places, but that's still better than what we have now.
(In reply to neil@parkwaycc.co.uk from comment #37)
> (In reply to alta88 from comment #35)
> > folder.setStringProperty will store in panacea.dat and does not in fact need to
> > access the big point of failure here (and elsewhere), which is folder.msgDatabase.
> It stores it in both places, but that's still better than what we have now.

sorry, that's not correct.  setStringProperty stores only in panacea.dat and does not need msgDatabase.
(In reply to alta88 from comment #38)

> sorry, that's not correct.  setStringProperty stores only in panacea.dat and
> does not need msgDatabase.

Neil is right; it stores them in both places. This is the code that stores it in the db:

http://mxr.mozilla.org/comm-central/source/mailnews/base/util/nsMsgDBFolder.cpp#2179
i stand corrected.  in my test, i setStringProperty, deleted the folder's .msf, and getStringProperty retrieved the value (without the folder being selected).  the code is clear, try panacea first then .msf, so technically .msf can be gone.

as a best practice, it still seems better to go through get/setStringProperty, no?
(In reply to alta88 from comment #41)

> as a best practice, it still seems better to go through
> get/setStringProperty, no?

Yes, because in theory the user can delete panacea.dat, and it needs to be able to be recreated from the .msf files.
And vice versa, of course.

(In reply to neil@parkwaycc.co.uk from comment #39)
> Use the source Luke:

nice one.  perhaps you can hover over to bug 705504.
Comment on attachment 577337 [details] [diff] [review]
stop db's from getting out of date

Sorry, I don't understand this; OnStopRequest already seems to do this.
Attachment #577337 - Flags: review?(neil)
OnStopRequest is called before the flush of the outputstream, and the close, which means the folder can have a later timestamp.
Comment on attachment 577337 [details] [diff] [review]
stop db's from getting out of date

At some point, I believe the flush was moved outside the loop, to speed up performance.
Attachment #577337 - Flags: review?(neil)
Comment on attachment 577337 [details] [diff] [review]
stop db's from getting out of date

Thanks, that makes sense now.
Attachment #577337 - Flags: review?(neil) → review+
http://hg.mozilla.org/comm-central/rev/cd77f678aa1c - this, in conjunction with the other fixes alta88 is working on, should fix this.
Status: NEW → RESOLVED
Closed: 13 years ago
Resolution: --- → FIXED
Attachment #577337 - Flags: approval-comm-beta+
Attachment #577337 - Flags: approval-comm-aurora+
Target Milestone: --- → Thunderbird 11.0
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: