Closed Bug 386739 Opened 17 years ago Closed 17 years ago

File > Import causes Bookmarks and History to disappear on restart

Categories

(Firefox :: Bookmarks & History, defect)

x86
Windows XP
defect
Not set
critical

Tracking

()

VERIFIED FIXED
Firefox 3 alpha7

People

(Reporter: tracy, Assigned: moco)

References

Details

(Keywords: regression)

Attachments

(4 files)

Attached image Assert dialog on restart after Import (deleted) —
seen with Trunk builds of 2007-07-03-04 -Clean Profile install -Import all settings from IE with File > Import -Shut down then restart Test results: -Bookmarks and History are gone -Assert appears in background on restart -Assert appears if Bookmarks or History menus are clicked and then clicked away from. Expected results: normal Bookmarks and History operation note: If I try to remove the affected profile I get an error saying content-prefs.sqlite can't be deleted because it is in use. Restart after the attempted, but not complete, profile deletion everything seems restored.; bookmarks and history are back.
investigating. tracy, anything in your js console? from those asserts, I wonder if we are failing to init one of the places services?
Assignee: nobody → sspitzer
oh, just crashed in dismissing the Menu Item Assert dialog this is in the Error console: Error: [Exception... "Component returned failure code: 0x80570016 (NS_ERROR_XPC_GS_RETURNED_FAILURE) [nsIJSCID.getService]" nsresult: "0x80570016 (NS_ERROR_XPC_GS_RETURNED_FAILURE)" location: "JS frame :: file:///C:/Program%20Files/Minefield/components/nsBrowserGlue.js :: bg__initPlaces :: line 297" data: no] Source File: file:///C:/Program%20Files/Minefield/components/nsBrowserGlue.js Line: 297 and several of these: Error: uncaught exception: [Exception... "Component returned failure code: 0x80570016 (NS_ERROR_XPC_GS_RETURNED_FAILURE) [nsIJSCID.getService]" nsresult: "0x80570016 (NS_ERROR_XPC_GS_RETURNED_FAILURE)" location: "JS frame :: chrome://browser/content/places/controller.js :: <TOP_LEVEL> :: line 1502" data: no]
Also, it seems if you wait long enough to restart, then everything is okay. It's taking something a while to setup. my IE profile is very large. ispiked just confirmed on XP. Tomcat wasn't able to reproduce on Vista and I wasn't able to do so on MAc.
Severity: blocker → critical
Keywords: smoketest
(In reply to comment #4) > Also, it seems if you wait long enough to restart, then everything is okay. > It's taking something a while to setup. my IE profile is very large. correction: my IE profile is NOT very large.
> If I try to remove the affected profile I get an error saying content- > prefs.sqlite can't be deleted because it is in use. Have you had that problem in any other scenario? (cc'ing myk)
twalker, thanks for the console errors. Those look like failures to create the places services, and I'll investigate as soon as my build is done.
Status: NEW → ASSIGNED
Flags: blocking-firefox3?
Target Milestone: --- → Firefox 3 beta1
> note: If I try to remove the affected profile I get an error saying > content-prefs.sqlite can't be deleted because it is in use. Did you try to remove the profile via the "Delete Profile..." button in the Profile Manager, and if so, did you access the profile manager by starting up Firefox? In theory the content prefs service shouldn't exist until the first browser window opens, and that's the only code that holds a database connection to content-prefs.sqlite. But perhaps there are circumstances under which the service starts up early. Or, if you're switching profiles in a running Firefox, which I've heard can be done (perhaps via an extension, although I can't find the extension that does it now), then maybe the issue is that the service doesn't shut down the DB connection to the database in the old profile during the "change profile" event, so you can't subsequently delete the old profile.
Myk, I'm not doing anything as complicated as any scenario you mentioned. I'm simply deleting the Firefox folder in Application Data\Mozilla\ I'm struggling to track down a regression range as this seems to be a timing issue. When I run smoketests I normally wouldn't see this. The import test is in the middle of the set, which allows enough time for whatever is taking so much time to initialize. But today I missed that test and didn't run it near the end. Anyway, if I run through the STR quickly enough I've found this bug back to 6/22. In builds prior to that I have't reproduced it but get an Alert Dialog on Restart that says " There was and error writing data to disk. This error is sometimes caused by a full disk. Please restart this application" [OK] my disk is not near full.
The problem, as I observed it, seems to be that the firefox.exe process doesn't exit properly when quitting after importing. So when you launch Firefox again, the other process the other process is zombied, but still hanging onto the db files, disallowing the new one to access them.
Adam, thanks for your comment about the firefox.exe process. I was able to reproduce this bug by attempting to start firefox while we were shutting down. It seems that after import, we appear to be taking a long time to shut down. (Not sure where, I'll attach in the debugger.) But see also bug #386286. In both bugs, firefox is taking a long time to shut down, but it is in the process of shutting down, so we are failing to create some services. That could also explains why when twalker attempts to remove the profile directory, he fails (and why content-prefs.sqlite is in use.) > Also, it seems if you wait long enough to restart, then everything is okay. That makes sense as well. For your "import from ie" scenario, I'll debug to see why shutdown might be taking so long. But it seems like there might be a general problem of trying to launch a browser window (handle a DDE command?) when firefox.exe is shutting down.
Yeah, we should probably call nativeappsupport::stop pretty early in the shutdown process (i.e. at quit-application-granted). http://mxr.mozilla.org/mozilla/source/toolkit/xre/nsNativeAppSupportWin.cpp#767 Right now I can't find the caller for that function at all, which is slightly worrisome.
breaking on shutdown, we appear to be waiting for nsThread::Shutdown() to finish (context.shutdownAck takes a long time to become non zero) so we call NS_ProcessNextEvent(context.joiningThread); in a while loop. ntdll.dll!7c90eb94() [Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll] user32.dll!7e4193e9() user32.dll!7e4193a8() user32.dll!7e419402() gkwidget.dll!PeekKeyAndIMEMessage(tagMSG * msg=0x0012f8c8, HWND__ * hwnd=0x00000000) Line 53 + 0x18 bytes C++ gkwidget.dll!nsAppShell::ProcessNextNativeEvent(int mayWait=0) Line 142 + 0xb bytes C++ gkwidget.dll!nsBaseAppShell::DoProcessNextNativeEvent(int mayWait=0) Line 137 + 0x11 bytes C++ gkwidget.dll!nsBaseAppShell::OnProcessNextEvent(nsIThreadInternal * thr=0x00b8f430, int mayWait=1, unsigned int recursionDepth=0) Line 225 + 0xd bytes C++ xpcom_core.dll!nsThread::ProcessNextEvent(int mayWait=1, int * result=0x0012f980) Line 472 C++ xpcom_core.dll!NS_ProcessNextEvent_P(nsIThread * thread=0x00b8f430, int mayWait=1) Line 227 + 0x16 bytes C++ xpcom_core.dll!nsThread::Shutdown() Line 442 + 0xb bytes C++ tkitcmps.dll!nsUrlClassifierDBService::Shutdown() Line 1025 C++ tkitcmps.dll!nsUrlClassifierDBService::Observe(nsISupports * aSubject=0x00c85f74, const char * aTopic=0x0034e740, const unsigned short * aData=0x00000000) Line 997 C++ > xpcom_core.dll!nsObserverList::NotifyObservers(nsISupports * aSubject=0x00c85f74, const char * aTopic=0x0034e740, const unsigned short * someData=0x00000000) Line 129 C++ xpcom_core.dll!nsObserverService::NotifyObservers(nsISupports * aSubject=0x00c85f74, const char * aTopic=0x0034e740, const unsigned short * someData=0x00000000) Line 184 C++ xpcom_core.dll!NS_ShutdownXPCOM_P(nsIServiceManager * servMgr=0x00c85f74) Line 721 C++ xul.dll!ScopedXPCOMStartup::~ScopedXPCOMStartup() Line 808 + 0xc bytes C++ xul.dll!XRE_main(int argc=2, char * * argv=0x00b898e0, const nsXREAppData * aAppData=0x00b8ab30) Line 2934 C++ firefox.exe!main(int argc=2, char * * argv=0x00b898e0) Line 87 + 0x12 bytes C++ firefox.exe!__tmainCRTStartup() Line 586 + 0x19 bytes C firefox.exe!mainCRTStartup() Line 403 C kernel32.dll!7c816fd7()
benjamin, while debugging, it doesn't look like DDE is the problem here. I am seeing us call nativeappsupport::quit() pretty early on. Then, when I hit this bug, I then get two firefox.exe processes. rob strong noticed that my parent.lock file has been removed, yet firefox.exe is still around. So when we launch the second instance of firefox, it launches against the same profile, and so the places.sqlite file is in use, so we get the problem that twalker reported.
benjamin, in XRE_main() we unlock the profile and then the our xpcom object (ScopedXPCOMStartup) goes out of scope. in ScopedXPCOMStartup::~ScopedXPCOMStartup(), we call NS_ShutdownXPCOMStartup(), see my stack in comment #13. perhaps we need to move the unlock until after the xpcom object goes out of scope? of course, we still have a problem here that the nsUrlClassifierDBService is taking a long time to shut down (in twalker's scenario) but this would help prevent problems on slow shutdown, right?
Attached patch patch (deleted) — Splinter Review
with this patch, when you hit a "slow shutdown" problem, the user will get the "firefox is running" alert. (screen shot coming)
Attachment #270797 - Flags: review?(benjamin)
this fix will also help with bug #386286 Note to bsmedberg / tony / et al: we still have a problem that doing what twalker describes takes a long time to shutdown [under nsUrlClassifierDBService::Shutdown], so that should be spun off. but with this patch (assuming bsmedberg thinks it is ok), we lock the profile longer during a slow shutdown.
Comment on attachment 270797 [details] [diff] [review] patch This is incorrect. The profile is officially no longer in use once we finish firing the "profile-before-change" notification. Places must watch this notification and finish any tasks that use the places DB during it.
Attachment #270797 - Flags: review?(benjamin) → review-
benjamin, thanks for the feedback. If we observe that notification, we won't have the "places.sqlite file in use" problem (which leads to the bug that twalker is seeing.) I also think the url classifier may also need to heed that profile notification (instead of shutdown?) and perhaps other consumers of SQLite. But say we fix all of those instances. If the scenario below happens, is it expected and working as designed? 1) the profile changing notifications have fired and all the work has completed, including the work in nsUrlClassifierDBService() and other sqlite consumers that might take a while 2) we unlock the profile (as currently implemented, before xpcom object goes out of scope) 3) but for some other reason xpcom shutdown takes a long time (see bug #386286) 4) during that "long time" of shutting down, someone attempts to start another firefox process 5) another firefox process starts up, so we have two running until the first one (which is being slow to shutdown) exits
Yes, I would expect that behavior and don't see any problems with it... do you? It's much like using multiple profiles.
> Yes, I would expect that behavior and don't see any problems with it... > do you? It's much like using multiple profiles. Thanks for the quick response and for clarifying. I wanted to make sure I understood the expected behaviour. Off the top of my head, I don't see any problems with it. So, going forward: 1) fix places to observe the profile-before-change notification (to fix this bug) 2) fix urldbclassifier to observe profile-before-change notification (instead of shutdown) in a spin off bug. 3) audit other sqlite consumers in our code (and log spin off bugs if necessary) cc'ing dwitte, sdwilsh, dolske and other folks using sqlite in our code.
benjamin, I'm not sure that profile-before-change the correct notification. I've added a listener to nsNavHistory, but it gets notified from nsXREDirProvider::DoShutdown(), which gets called when the xpcom object goes out of scope. But that happens after we call profileLock->Unlock(); so listening for that notifcation won't help with this bug. Is there a better notification I should be listening for, or, should we reconsider moving the unlock() call? places.dll!nsNavHistory::Observe(nsISupports * aSubject=0x04058688, const char * aTopic=0x10036368, const unsigned short * aData=0x10036a00) Line 3112 C++ xpcom_core.dll!nsObserverList::NotifyObservers(nsISupports * aSubject=0x04058688, const char * aTopic=0x10036368, const unsigned short * someData=0x10036a00) Line 129 C++ xpcom_core.dll!nsObserverService::NotifyObservers(nsISupports * aSubject=0x04058688, const char * aTopic=0x10036368, const unsigned short * someData=0x10036a00) Line 184 C++ > xul.dll!nsXREDirProvider::DoShutdown() Line 766 C++ xul.dll!ScopedXPCOMStartup::~ScopedXPCOMStartup() Line 806 C++ xul.dll!XRE_main(int argc=2, char * * argv=0x00b898a8, const nsXREAppData * aAppData=0x00b8aaf8) Line 2934 C++ firefox.exe!main(int argc=2, char * * argv=0x00b898a8) Line 87 + 0x12 bytes C++ firefox.exe!__tmainCRTStartup() Line 586 + 0x19 bytes C firefox.exe!mainCRTStartup() Line 403 C kernel32.dll!7c816fd7() [Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll] profileLock->Unlock(); places.dll!nsNavHistory::Observe(nsISupports * aSubject=0x04058688, const char * aTopic=0x10036368, const unsigned short * aData=0x10036a00) Line 3112 C++ xpcom_core.dll!nsObserverList::NotifyObservers(nsISupports * aSubject=0x04058688, const char * aTopic=0x10036368, const unsigned short * someData=0x10036a00) Line 129 C++ xpcom_core.dll!nsObserverService::NotifyObservers(nsISupports * aSubject=0x04058688, const char * aTopic=0x10036368, const unsigned short * someData=0x10036a00) Line 184 C++ > xul.dll!nsXREDirProvider::DoShutdown() Line 766 C++ xul.dll!ScopedXPCOMStartup::~ScopedXPCOMStartup() Line 806 C++ xul.dll!XRE_main(int argc=2, char * * argv=0x00b898a8, const nsXREAppData * aAppData=0x00b8aaf8) Line 2934 C++ firefox.exe!main(int argc=2, char * * argv=0x00b898a8) Line 87 + 0x12 bytes C++ firefox.exe!__tmainCRTStartup() Line 586 + 0x19 bytes C firefox.exe!mainCRTStartup() Line 403 C kernel32.dll!7c816fd7() [Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll]
Yeah, it looks like the call to Unlock is misplaced. I believe that it should be on line 2932 instead of 2930: http://bonsai.mozilla.org/cvsblame.cgi?file=/mozilla/toolkit/xre/nsAppRunner.cpp&rev=1.176&mark=2930,2932#2930
Attachment #270797 - Flags: review- → review?(benjamin)
> Yeah, it looks like the call to Unlock is misplaced. > I believe that it should be on line 2932 instead of 2930 Benjamin, thanks for the response. That's what my earlier patch did, so I'm seeking a re-review from you.
Seth, do you know what the other threads are doing while the UI thread is waiting for nsThread::Shutdown()? My guess is that the url classifier thread is in nsUrlClassifierDBServiceWorker::Update. If so, spin off another bug and I'll look into making the shutdown faster.
Seth, could you clarify what the sqlite issue is here? I don't quite follow.
Flags: in-testsuite?
Attachment #270797 - Flags: review?(robert.bugzilla)
Comment on attachment 270797 [details] [diff] [review] patch Yeah, I'd really prefer to unlock it after we fire the profile-changed notifications, but I can't see a simple way to do that.
Attachment #270797 - Flags: review?(benjamin) → review+
Attachment #270797 - Flags: review?(robert.bugzilla) → review+
> My guess is that the url classifier thread is in nsUrlClassifierDBServiceWorker::Update Tony, sorry for the delay. We appear to be in nsUrlClassifierDBServiceWorker::CloseDb() which calls mozStorageService::FlushAsyncIO() nsUrlClassifierDBServiceWorker::Update() ntdll.dll!7c90eb94() [Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll] ntdll.dll!7c90e9c0() kernel32.dll!7c8025cb() msvcr80d.dll!malloc(unsigned int nSize=848) Line 152 + 0x15 bytes C++ kernel32.dll!7c802532() nspr4.dll!_PR_MD_WAIT_CV(_MDCVar * cv=0x05f5f65c, _MDLock * lock=0x05e27344, unsigned int timeout=4294967295) Line 280 + 0x14 bytes C nspr4.dll!_PR_WaitCondVar(PRThread * thread=0x05c15100, PRCondVar * cvar=0x05f5f5e8, PRLock * lock=0x05e27328, unsigned int timeout=4294967295) Line 204 + 0x17 bytes C nspr4.dll!PR_WaitCondVar(PRCondVar * cvar=0x05f5f5e8, unsigned int timeout=4294967295) Line 551 + 0x17 bytes C strgcmps.dll!mozStorageService::FlushAsyncIO() Line 581 + 0xc bytes C++ strgcmps.dll!mozStorageConnection::~mozStorageConnection() Line 91 C++ strgcmps.dll!mozStorageConnection::`scalar deleting destructor'() + 0xf bytes C++ strgcmps.dll!mozStorageConnection::Release() Line 68 + 0xce bytes C++ tkitcmps.dll!nsUrlClassifierDBServiceWorker::CloseDb() Line 513 + 0x14 bytes C++ xpcom_core.dll!NS_InvokeByIndex_P(nsISupports * that=0x00000009, unsigned int methodIndex=0, unsigned int paramCount=0, nsXPTCVariant * params=0x06a2ff04) Line 102 C++ xpcom_core.dll!nsProxyObjectCallInfo::Run() Line 181 + 0x2d bytes C++ xpcom_core.dll!nsProxyObjectCallInfo::Run() Line 181 + 0x2d bytes C++ xpcom_core.dll!nsThread::ProcessNextEvent(int mayWait=1, int * result=0x06a2ff1c) Line 491 C++ xpcom_core.dll!NS_ProcessNextEvent_P(nsIThread * thread=0x05c14b78, int mayWait=1) Line 227 + 0x16 bytes C++ xpcom_core.dll!nsThread::ThreadFunc(void * arg=0x05c14b78) Line 254 + 0xb bytes C++ nspr4.dll!_PR_NativeRunThread(void * arg=0x05c15100) Line 436 + 0xf bytes C nspr4.dll!pr_root(void * arg=0x05c15100) Line 122 + 0xf bytes C msvcr80d.dll!_callthreadstartex() Line 348 + 0xf bytes C msvcr80d.dll!_threadstartex(void * ptd=0x05c15aa0) Line 331 C kernel32.dll!7c80b683() ntdll.dll!7c90eb94() [Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll] user32.dll!7e4193e9() user32.dll!7e4193a8() user32.dll!7e419402() gkwidget.dll!PeekKeyAndIMEMessage(tagMSG * msg=0x0012f8c8, HWND__ * hwnd=0x00000000) Line 53 + 0x18 bytes C++ gkwidget.dll!nsAppShell::ProcessNextNativeEvent(int mayWait=0) Line 142 + 0xb bytes C++ gkwidget.dll!nsBaseAppShell::DoProcessNextNativeEvent(int mayWait=0) Line 137 + 0x11 bytes C++ gkwidget.dll!nsBaseAppShell::OnProcessNextEvent(nsIThreadInternal * thr=0x00b9dc38, int mayWait=1, unsigned int recursionDepth=0) Line 225 + 0xd bytes C++ xpcom_core.dll!nsThread::ProcessNextEvent(int mayWait=1, int * result=0x0012f988) Line 480 C++ xpcom_core.dll!NS_ProcessNextEvent_P(nsIThread * thread=0x00b9dc38, int mayWait=1) Line 227 + 0x16 bytes C++ xpcom_core.dll!nsThread::Shutdown() Line 445 + 0xb bytes C++ tkitcmps.dll!nsUrlClassifierDBService::Shutdown() Line 1030 C++ tkitcmps.dll!nsUrlClassifierDBService::Observe(nsISupports * aSubject=0x0490c858, const char * aTopic=0x10036698, const unsigned short * aData=0x10036d30) Line 1000 C++ xpcom_core.dll!nsObserverList::NotifyObservers(nsISupports * aSubject=0x0490c858, const char * aTopic=0x10036698, const unsigned short * someData=0x10036d30) Line 129 C++ xpcom_core.dll!nsObserverService::NotifyObservers(nsISupports * aSubject=0x0490c858, const char * aTopic=0x10036698, const unsigned short * someData=0x10036d30) Line 184 C++ xul.dll!nsXREDirProvider::DoShutdown() Line 766 C++ xul.dll!ScopedXPCOMStartup::~ScopedXPCOMStartup() Line 819 C++ xul.dll!XRE_main(int argc=2, char * * argv=0x00b99850, const nsXREAppData * aAppData=0x00b9aaa0) Line 3003 C++ firefox.exe!main(int argc=2, char * * argv=0x00b99850) Line 87 + 0x12 bytes C++ firefox.exe!__tmainCRTStartup() Line 586 + 0x19 bytes C firefox.exe!mainCRTStartup() Line 403 C kernel32.dll!7c816fd7() ntdll.dll!7c90eb94() [Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll] ntdll.dll!7c90d9d6() kernel32.dll!7c81268b() strgcmps.dll!winSync(OsFile * id=0x00d8b1a8, int dataOnly=0) Line 16081 + 0xd bytes C > strgcmps.dll!ProcessOneMessage(AsyncMessage * aMessage=0x0602f4b8) Line 1401 + 0x11 bytes C++ strgcmps.dll!ProcessAsyncMessages() Line 1534 + 0x9 bytes C++ strgcmps.dll!AsyncWriteThread::Run() Line 475 C++ xpcom_core.dll!nsThread::ProcessNextEvent(int mayWait=1, int * result=0x041aff1c) Line 491 C++ xpcom_core.dll!NS_ProcessNextEvent_P(nsIThread * thread=0x00ee5878, int mayWait=1) Line 227 + 0x16 bytes C++ xpcom_core.dll!nsThread::ThreadFunc(void * arg=0x00ee5878) Line 254 + 0xb bytes C++ nspr4.dll!_PR_NativeRunThread(void * arg=0x03d756c8) Line 436 + 0xf bytes C nspr4.dll!pr_root(void * arg=0x03d756c8) Line 122 + 0xf bytes C msvcr80d.dll!_callthreadstartex() Line 348 + 0xf bytes C msvcr80d.dll!_threadstartex(void * ptd=0x03d14a00) Line 331 C kernel32.dll!7c80b683() I'll log a spin off bug about how in this scenario quitting the browser can take a long time.
fixed. Checking in nsAppRunner.cpp; /cvsroot/mozilla/toolkit/xre/nsAppRunner.cpp,v <-- nsAppRunner.cpp new revision: 1.179; previous revision: 1.178 done
Status: ASSIGNED → RESOLVED
Closed: 17 years ago
Resolution: --- → FIXED
note, after this fix, with Tracy's steps, you will now see the alert in attachment #270798 [details] if you start up during shutdown. I've spun the "takes a long time to shutdown" issue out to bug #387830
No longer blocks: 387830
Verified with: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9a7pre) Gecko/2007071213 Minefield/3.0a7pre
Status: RESOLVED → VERIFIED
Flags: blocking-firefox3? → blocking-firefox3+
Flags: in-testsuite? → in-litmus?
Tracy found this bug when running this smoketest, IIRC: http://litmus.mozilla.org/show_test.cgi?id=3949. Marking in-litmus+.
Flags: in-litmus? → in-litmus+
Bug 451915 - move Firefox/Places bugs to Firefox/Bookmarks and History. Remove all bugspam from this move by filtering for the string "places-to-b-and-h". In Thunderbird 3.0b, you do that as follows: Tools | Message Filters Make sure the correct account is selected. Click "New" Conditions: Body contains places-to-b-and-h Change the action to "Delete Message". Select "Manually Run" from the dropdown at the top. Click OK. Select the filter in the list, make sure "Inbox" is selected at the bottom, and click "Run Now". This should delete all the bugspam. You can then delete the filter. Gerv
Component: Places → Bookmarks & History
QA Contact: places → bookmarks
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: