Overview Description: File | Exit throws an assertion. Build Date & Platform Bug Found: 8/19/99. windows debug build. I pulled the tree around 10.00 AM. Steps to Reproduce: 1. Start messenger using Task | Messenger. 2. Do File | Exit. Throws an assertion. Here is the Stack trace. NTDLL! 77f7629c() nsDebug::Assertion(const char * 0x01876c08, const char * 0x01876b24, const char * 0x01876af4, int 74) line 176 + 13 bytes mork_assertion_signal(const char * 0x01876c08) line 74 + 31 bytes morkEnv::NewError(const char * 0x01876ff0) line 362 + 19 bytes morkStore::CannotAutoAssignAtomIdentityError(morkEnv * 0x04886e10) line 641 morkAtomSpace::MakeBookAtomCopy(morkEnv * 0x04886e10, const morkBigBookAtom & {...}) line 229 + 9 bytes morkStore::YarnToAtom(morkEnv * 0x04886e10, const mdbYarn * 0x0012d948) line 719 + 16 bytes morkBuilder::OnValue(morkEnv * 0x04886e10, const morkSpan & {...}, const morkBuf & {...}) line 836 + 16 bytes morkParser::ReadCell(morkEnv * 0x04886e10) line 565 morkParser::ReadRow(morkEnv * 0x04886e10, int 40) line 651 morkParser::ReadContent(morkEnv * 0x04886e10, unsigned char 1) line 1314 morkParser::ReadGroup(morkEnv * 0x04886e10) line 1115 morkParser::ReadAt(morkEnv * 0x04886e10, unsigned char 0) line 1148 morkParser::ReadContent(morkEnv * 0x04886e10, unsigned char 0) line 1325 + 16 bytes morkParser::OnPortState(morkEnv * 0x04886e10) line 1359 + 14 bytes morkParser::ParseLoop(morkEnv * 0x04886e10) line 1415 + 12 bytes morkParser::ParseMore(morkEnv * 0x04886e10, long * 0x0012da90, unsigned char * 0x04886634, unsigned char * 0x04886635) line 1454 morkThumb::DoMore_OpenFileStore(morkEnv * 0x04886e10) line 432 morkThumb::DoMore(morkEnv * 0x04886e10, unsigned long * 0x0012db2c, unsigned long * 0x0012db24, unsigned char * 0x0012db30, unsigned char * 0x0012db28) line 352 + 12 bytes orkinThumb::DoMore(nsIMdbEnv * 0x04883358, unsigned long * 0x0012db2c, unsigned long * 0x0012db24, unsigned char * 0x0012db30, unsigned char * 0x0012db28) line 225 nsMsgDatabase::OpenMDB(nsMsgDatabase * const 0x04884cb0, const char * 0x04886e88, int 0) line 611 + 46 bytes nsImapMailDatabase::Open(nsImapMailDatabase * const 0x048841d0, nsIFileSpec * 0x04882c00, int 0, int 0, nsIMsgDatabase * * 0x0012de98) line 89 + 29 bytes nsImapMailFolder::GetDBFolderInfoAndDB(nsIDBFolderInfo * * 0x0012def4, nsIMsgDatabase * * 0x0012def0) line 877 + 40 bytes nsMsgDBFolder::ReadDBFolderInfo(int 0) line 212 + 59 bytes nsImapMailFolder::UpdateSummaryTotals(nsImapMailFolder * const 0x03b5f87c, int 0) line 653 nsImapMailFolder::GetSubFolders(nsImapMailFolder * const 0x03b5f87c, nsIEnumerator * * 0x0012dfdc) line 352 nsMsgDBFolder::WriteToFolderCache(nsMsgDBFolder * const 0x03b5f87c, nsIMsgFolderCache * 0x037caed0) line 391 + 36 bytes nsMsgDBFolder::WriteToFolderCache(nsMsgDBFolder * const 0x03b5404c, nsIMsgFolderCache * 0x037caed0) line 419 + 30 bytes nsMsgIncomingServer::WriteToFolderCache(nsMsgIncomingServer * const 0x037c9970, nsIMsgFolderCache * 0x037caed0) line 109 + 30 bytes nsMsgAccountManager::hashTableWriteFolderCache(nsHashKey * 0x037caf30, void * 0x037c9e80, void * 0x037caed0) line 661 _hashEnumerate(PLHashEntry * 0x037c9bd0, int 4, void * 0x0012e0e0) line 85 + 26 bytes PL_HashTableEnumerateEntries(PLHashTable * 0x037c7780, int (PLHashEntry *, int, void *)* 0x10014c90 _hashEnumerate(PLHashEntry *, int, void *), void * 0x0012e0e0) line 368 + 15 bytes nsHashtable::Enumerate(int (nsHashKey *, void *, void *)* 0x015c6610 nsMsgAccountManager::hashTableWriteFolderCache(nsHashKey *, void *, void *), void * 0x037caed0) line 214 + 20 bytes nsMsgAccountManager::WriteToFolderCache(nsMsgAccountManager * const 0x037c7810, nsIMsgFolderCache * 0x037caed0) line 875 nsMsgMailSession::~nsMsgMailSession() line 57 nsMsgMailSession::`scalar deleting destructor'(unsigned int 1) + 15 bytes nsMsgMailSession::Release(nsMsgMailSession * const 0x037c7910) line 31 + 96 bytes DeleteEntry(nsHashKey * 0x0012e188, void * 0x037c9150, void * 0x00000000) line 168 + 18 bytes nsObjectHashtable::RemoveAndDelete(nsHashKey * 0x0012e188) line 370 + 21 bytes nsServiceManagerImpl::UnregisterService(nsServiceManagerImpl * const 0x00e917c0, const nsID & {...}) line 356 nsServiceManagerImpl::UnregisterService(nsServiceManagerImpl * const 0x00e917c0, const char * 0x015ebd5c) line 381 nsServiceManager::UnregisterService(const char * 0x015ebd5c) line 525 nsMessengerBootstrap::Shutdown(nsMessengerBootstrap * const 0x00f35bb0) line 68 + 11 bytes nsAppShellService::ShutdownComponent(const nsID & {...}) line 444 + 12 bytes nsAppShellService::EnumerateComponents(void (const nsID &)* 0x00fb1668 nsAppShellService::ShutdownComponent(struct nsID const &)) line 365 nsAppShellService::Shutdown(nsAppShellService * const 0x00f3dd20) line 487 nsEditorShell::Exit(nsEditorShell * const 0x04414290) line 1077 XPTC_InvokeByIndex(nsISupports * 0x04414290, unsigned int 24, unsigned int 0, nsXPTCVariant * 0x0012e3f8) line 135 nsXPCWrappedNativeClass::CallWrappedMethod(JSContext * 0x0372e7c0, nsXPCWrappedNative * 0x04870080, const XPCNativeMemberDescriptor * 0x03fed1b8, nsXPCWrappedNativeClass::CallMode CALL_METHOD, unsigned int 0, long * 0x011dacec, long * 0x0012e600) line 511 + 44 bytes WrappedNative_CallMethod(JSContext * 0x0372e7c0, JSObject * 0x02e83928, unsigned int 0, long * 0x011dacec, long * 0x0012e600) line 130 js_Invoke(JSContext * 0x0372e7c0, unsigned int 0, unsigned int 0) line 654 + 26 bytes js_Interpret(JSContext * 0x0372e7c0, long * 0x0012ee2c) line 2228 + 15 bytes js_Invoke(JSContext * 0x0372e7c0, unsigned int 0, unsigned int 0) line 670 + 13 bytes js_Interpret(JSContext * 0x0372e7c0, long * 0x0012f614) line 2228 + 15 bytes js_Invoke(JSContext * 0x0372e7c0, unsigned int 1, unsigned int 2) line 670 + 13 bytes js_InternalCall(JSContext * 0x0372e7c0, JSObject * 0x02dfa4a8, long 48211120, unsigned int 1, long * 0x0012f754, long * 0x0012f75c) line 747 + 15 bytes JS_CallFunctionValue(JSContext * 0x0372e7c0, JSObject * 0x02dfa4a8, long 48211120, unsigned int 1, long * 0x0012f754, long * 0x0012f75c) line 2643 + 29 bytes nsJSEventListener::HandleEvent(nsIDOMEvent * 0x044305a0) line 97 + 34 bytes nsEventListenerManager::HandleEvent(nsIPresContext & {...}, nsEvent * 0x0012f92c, nsIDOMEvent * * 0x0012f8f4, unsigned int 3, nsEventStatus & nsEventStatus_eIgnore) line 1110 + 27 bytes RDFElementImpl::HandleDOMEvent(RDFElementImpl * const 0x03abb160, nsIPresContext & {...}, nsEvent * 0x0012f92c, nsIDOMEvent * * 0x0012f8f4, unsigned int 1, nsEventStatus & nsEventStatus_eIgnore) line 2392 nsMenuFrame::Execute() line 938 nsMenuFrame::HandleEvent(nsMenuFrame * const 0x03fcb9e8, nsIPresContext & {...}, nsGUIEvent * 0x0012fba0, nsEventStatus & nsEventStatus_eConsumeDoDefault) line 245 PresShell::HandleEvent(PresShell * const 0x0374fd74, nsIView * 0x03dbaea0, nsGUIEvent * 0x0012fba0, nsEventStatus & nsEventStatus_eConsumeDoDefault) line 1877 + 38 bytes nsView::HandleEvent(nsView * const 0x03dbaea0, nsGUIEvent * 0x0012fba0, unsigned int 8, nsEventStatus & nsEventStatus_eConsumeDoDefault, int & 0) line 835 nsView::HandleEvent(nsView * const 0x0374e1f0, nsGUIEvent * 0x0012fba0, unsigned int 28, nsEventStatus & nsEventStatus_eConsumeDoDefault, int & 0) line 820 nsViewManager::DispatchEvent(nsViewManager * const 0x0374e410, nsGUIEvent * 0x0012fba0, nsEventStatus & nsEventStatus_eConsumeDoDefault) line 1611 HandleEvent(nsGUIEvent * 0x0012fba0) line 67 nsWindow::DispatchEvent(nsWindow * const 0x03dba174, nsGUIEvent * 0x0012fba0, nsEventStatus & nsEventStatus_eIgnore) line 498 + 10 bytes nsWindow::DispatchWindowEvent(nsGUIEvent * 0x0012fba0) line 523 nsWindow::DispatchMouseEvent(unsigned int 301, nsPoint * 0x00000000) line 3271 + 21 bytes ChildWindow::DispatchMouseEvent(unsigned int 301, nsPoint * 0x00000000) line 3466 nsWindow::ProcessMessage(unsigned int 514, unsigned int 0, long 24182853, long * 0x0012fdd4) line 2539 + 24 bytes nsWindow::WindowProc(HWND__ * 0x03690be6, unsigned int 514, unsigned int 0, long 24182853) line 571 + 27 bytes USER32! 77e71820()

this is a mork problem, perhaps having to do with incremental writing.

This bug report is evidence of memory corruption, because the only way that assertion can fire is if mStore_CanAutoAssignAtomIdentity is false, and this is never true after you have successfully gotten a store from Mork. This is infrastructure for a feature that is not being used yet, so having it go belly up means that somebody stepped on the byte in the store object that keeps this boolean state. One of two things should be true: 1) the bug is not reproducible because the memory corruption was transient, or 2) somebody is corrupting memory the same way each time, due to recent changes in the tree. Putting a watch on that byte would be informative; I don't have a build that runs since I'm in the middle of mucking with my tree and Mork won't build for me. There is nothing for me to fix in Mork, but if I had free time I could sit and watch who steps on that byte.

fyi: This bug can be reproduced.

Would it be useful for you to sit with Suresh for a few minutes to see this David?

Yes, but only if we can set a data breakpoint on the morkStore slot mStore_CanAutoAssignAtomIdentity, to see the memory corruption.

Suresh - if you can do as David suggests, pls work with him on this. Thanks.

David Bienvenu reasoned out that this is likely not memory corruption, since the relevant boolean starts at false, and only becomes true after parsing is done; so this bug means parsing the file was unhappy. I need a file to load to see what happens -- emailing one to me works best. David B says he can get me one after he builds, but it's fine if someone beats he to the punch. (And I need to build myself before I can run.) So the code doesn't like something about the file being parsed; it could be I'm writing it wrong or reading it wrong. Or less likely, the file could be corrupt, but I don't expect that. So far I'm thinking maybe I fail to write a atom def in a dict before some literat string appears.

davidmc - did you get what you need to look further into this bug? Thanks.

Suresh reported a strange Mork bug, which David Bienvenu tracked down in a debugger for me (see http://bugzilla.mozilla.org/show_bug.cgi?id=12139). I have a relatively easy fix, but I'm trying to come up with a rational explanation that demonstrates why this very non-intuitive effect is a natural result of the differences in reference models used by the runtime and by the serialized text format under incremental updating. Someone maintaining Mork, or anyone developing an entirely different kind of system, but along the same general lines, would want to know exactly why this situation can arise. The logic seems pretty edgy. The cause of the problem was this: when putting a new string value as an atom into a row's cell, we cut any old atom that once lived there. As it happened, I was keeping track of how many times an atom was referenced, so I could delete it at zero refs. And I was doing this while parsing a Mork file, which incrementally updated a row, putting a new atom value in place of an old one. This caused a tenuous chain of circumstances about three levels removed which caused an assert. The problem would go away if we always kept atoms, even at zero refs, and just let them get collected only during compress commits. But it would also go away if we merely avoided zapping them at zero refs while parsing, but permitted them to zap later after a store opens. This rest of this explains exactly what was wrong. It's interesting in a hairy kind of way; you'd want to know about this case if you were toubleshooting weird text parsing errors involving identity. Here is a Mork fragment which might now fail when parsed: <(666=6)> // this dict defines hex 0x666 to identify string "6" [500:m (^90=6)] // row 500:m has a column ^90 containing "6" @$${8{@ // beginning of transaction 0x8 <(444=4)> // this dict defines hex 0x444 to identify string "4" [500:m (^90=4)] // change value of col ^90 in row 500:m to "4" [600:m (^90=6)] // set value of col ^90 in row 600:m to "6" @$$}8}@ // end of transaction 0x8 Presumably string "6" is entered in the dict at first because it has never been written before, but we want it defined before first use in row 500:m that follows. This means the atom in that cell of the row has but a single reference. (Note the reason we write a value as "=6" instead of using "^666" is because the former is shorter and makes the file smaller. We want strings to have well-defined atom identity token numbers, but we can use the shorter representation in actual usage; when parsed, we look up the string in the dict and find the atome token ID, and that is why thy atom had better appear in the dict before usage.) So in the subsequent incremental update within transaction 8, when we change the value of col ^90 in row 500:m to "4", this causes the last ref to atom 0x666 to go away, and it gets deleted so it is no longer in the atom dict. But then the very next row 600:m puts string "6" into col ^90 and we cannot find the associated atom in the dict while parsing, and this is where the assert comes from when opening the store, because every string used must already be in the atom dict. (The reason every atom must already be in the dict is to avoid any event of auto-ID assignment that is followed later by explicit ID assignment. If we saw "6" and could not find it in the dict, and so assigned next ID 0x76548, and then later saw <(666=6)> which gives string "6" an ID explicitly, we'd then have a conflict. We might fix this by replacing the 0x76548 ID with 0x666, but this would tend to drop 0x76548 on the floor unused, with a net effect of consuming the ID space faster than necessary. It's hard to put the ID counter backward in time when it allocates a mixed sequence of IDs that do and don't get used.) So how did the Mork text file get that way in the first place? Why did the second use of "6" not get a new ID at runtime, so that the file simply redefined "6" to use ID 0x76548 before use in row 600:m? Well, that probably did happen at runtime, but the Mork file could still be written the way we say because the count of references at runtime might not correspond to the count of atom refs as they seem when parsing the file in linear sequence. And this might interact with the fact that tables and rows get written in hash table order (which is pseudo-random), and this can cause refcounts of atoms to hit zero or not <em>depending on the order of writing</em>. Hmmm. After a store opens, we blithely auto-assign atom IDs whenever new atom values are needed. But when parsing a Mork file to prepare a store to be opened, we want to assert when auto-assignment happens because this shows we failed in our invariant that enforces all atoms are written in a dict before they appear in usage. Anyway, the Mork text format tends to assume that anything before a point in the text still exists, unless an explicit even happens to cut all content from a row or table. But the observed bug involves the death of an atom as a mere side effect of putting new content into a row, after the atom gets defined in a dict. All by itself, this seems questionable. So the best fix for this bug might involve turning off atom garbage collection at zero refs when still parsing a file. Or if that is at all hard to determine and control, then never collecting an atom would be second best. (And then atoms would be collected during a compress commit, since they would not be written unless in some row.) David Mc

When I saw I was cutting the old atom, I only had to reason out why I was doing that, and what the bad effects could be. I posted a longish post explaining in the newsgroup. Here is the second best fix as a temporary band-aid, until I do the better fix by only during it off when in the mode of parsing a file. This just comments out the code which would destory the atom on zero refs. I expect it should be okay to have the atom hang around with zero 'cell uses' since this is mostly advisory information. void morkCell::SetAtom(morkEnv* ev, morkAtom* ioAtom, morkPool* ioPool) { morkAtom* oldAtom = mCell_Atom; if ( oldAtom != ioAtom ) // ioAtom is not already installed in this cell? { if ( oldAtom ) { mCell_Atom = 0; if ( oldAtom->CutCellUse(ev) == 0 ) { // if ( ioPool ) // { // if ( oldAtom->IsBook() ) // ((morkBookAtom*) oldAtom)->CutBookAtomFromSpace(ev); // // ioPool->ZapAtom(ev, oldAtom); // } // else // ev->NilPointerError(); } } if ( ioAtom ) ioAtom->AddCellUse(ev); mCell_Atom = ioAtom; } }

No, I guess that is the permanent fix. We can't allow collection after the store is open, because then string re-use gets a new ID, and then that string gets two IDs in the Mork file when written incrementally, which sounds like a bad idea.

I'm not seeing this now. Is this fixed or worksforme?

This is fixed; guess I'd better clean up my bug list.

suresh - pls verify.

Marking this as Verified.