Closed Bug 280342 Opened 20 years ago Closed 19 years ago

History before yesterday disappears (Mork issue?)

Categories

(Camino Graveyard :: History, defect, P1)

Product:
Camino Graveyard
Component:
History
Platform:
PowerPC
macOS
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED FIXED
Milestone:
Camino0.9

People

(Reporter: camino, Assigned: sfraser_bugs)

References

Details

Attachments

(2 files)

Shows the empty history folders
25.07 KB, image/png
Details
error log
1020 bytes, text/plain
Details 
Sometimes (no steps to reproduces just yet) it will happen that history
instances before yesterday disappear for an unknown reason.

I also came accros a situation where when I viewed history the container was
completly empty. Only a re-launch showed history again.
Did you have any crashes that might have corrupted the history DB?
It's not corrupted, though, as far as I can tell. It just disappears until
Camino is relaunched.
I've had this happen twice in the past week (basically, after two days, the
entries are all gone (don't come up via auto-complete in the location bar,
either), although the folders still remain) on two different recent NBs (21st?
and 26th).

The first time there definitely had been a Camino crash during the two days
prior to history disappearing, but the history wasn't blank immediately after
the crash--rather, several launches later.

The most recent time I'm sure I was crash-free in the two-day period (i.e.,
since history had last vanished).

If it happens again I'll quit and relaunch to see if the history entries
reappear...it had never occurred to me to do that.
I didn't have a crash before it happened. And a releaunch didn't turn back the
history items before yesterday. This isn't very nice.

Just a wild guess here. I changed the remembered pages to 9 days. Maybe there is
something wacky with history when it surpasses the set of days to remember? 

I'm guessing this because at the moment my history is nicely filling up the days
again.
(In reply to comment #4)

> Just a wild guess here. I changed the remembered pages to 9 days. Maybe there is
> something wacky with history when it surpasses the set of days to remember?

That might explain my first brush with this bug, but not the second, as my
history was set to 9 days and the second brush was 2 days later....

Well, it just happened again.  I quit Camino not too long ago then fired it up
to check something else, and all the history items were gone (except my
homepage, which is loaded on opening a new window).  

The days/folders are all still there, but no history items to be found. Unlike
for Wevah and Jasper, quitting/restarting Camino did not bring the history items
back back.  After doing the quit/restart Camino process, the history.dat was 4k
(forgot to look before quit/restart)....

It's been just about two days now since it last happened.  I'm guessing based on
what I remember of the last time I paid attention to the number of entries in
history that I probably had ca. 500 entries stored from the the past two days.

2005012908 (v0.8+) (switched since shortly after the last time history items
diasppeared; no crashes in this timeframe, either) 
Had the same problem with 10.3.4 and the last nightly.
My url auto fill was not working as all my history is gone.
Just so people don't get confused.

Bug 280342 is about history instances that are gone for a yet unknown reason,
the folders are still shown but their content is gone. No fix is found yet.

Bug 278928 is about nothing at all showing in the history container, hidden so
to speek. A relaunch of Camino will then show them again correctly.
I might have to add some logging to the history DB code.
Status: NEW → ASSIGNED
Priority: -- → P1
Target Milestone: --- → Camino0.9
A bit more info that may or may not be useful:

I knew it was about time to lose my history again, so I started paying closer
attention (and, one time when Camino was quit, made a backup of history.dat).

My history.dat was 232 KB and had ca. 600 items in it when it "reverted" to
being 4K.  It was definitely "reverted" on or shortly after starting Camino
(rather than on quitting; because the Finder doesn't update its window contents
very well/quickly under OS X, esp. when it's in the background, I couldn't tell
if the clearing was really at launch or as soon as I started typing in the
location field).

I was able to copy back the backup copy of history.dat and have some history
again, but I don't yet know how long it will be before it is erased--and I only
quit/launch Camino about 3 times a day.

I'm of course more than happy to test a build with any debugging/logging code
you need :-)
I added some debug messages that will print to the console, even in release
builds. These look like:

On launch:

HISTORY DEBUG: historyFile exists: 1
HISTORY DEBUG: OpenExistingFile(/Users/smfr/Library/Application
Support/Camino/history.dat)
HISTORY DEBUG: OpenOldFile returned err 0x00000000 (file 0xedc55c)
HISTORY DEBUG: CanOpenFilePort returned err 0x00000000 (canopen 1)
HISTORY DEBUG: OpenFileStore returned err 0x00000000 (thumb 0xefc30c)
HISTORY DEBUG: DoMore or ThumbToOpenStore returned err 0x00000000
HISTORY DEBUG: CreateTokens returned err 0x00000000
HISTORY DEBUG: GetMetaRow return err 0x00000000

On quit:

HISTORY DEBUG: Commit() in CloseDB() returned err 0x00000000

If you lose history, pleaes look in your console.log for these messages. You
should look for the dumps for the start of the session where history has gone,
and the quit of the previous session.
You're saying I should have seen those last night when I lost history?  I did
look at the log last night but didn't see anything from Camino other than those
silly JS errors which fill up the logfiles.  

I just used the console's "filter" function on the last several days of logs and
there's no "HISTORY DEBUG" anywhere to be found.
It looks like he added those yesterday; they should be in today's build.
What ender said.
Sorry--it wasn't showing up in bonsai when I had last looked.  It'll be a few
days before I can provide any feedback because I'll be away and without 'net access.
Mac OS X Version 10.3.7 (Build 7T21)
2005-02-05 15:46:01 +1030
HISTORY DEBUG: historyFile exists: 1

HISTORY DEBUG: OpenExistingFile(/Users/marknewland/Library/Application
Support/Camino/history.dat)

HISTORY DEBUG: OpenOldFile returned err 0x00000000 (file 0x51ae1e8)

HISTORY DEBUG: CanOpenFilePort returned err 0x00000000 (canopen 1)

HISTORY DEBUG: OpenFileStore returned err 0x00000000 (thumb 0x51ac588)

HISTORY DEBUG: DoMore or ThumbToOpenStore returned err 0x00000000

HISTORY DEBUG: CreateTokens returned err 0x00000000

HISTORY DEBUG: GetMetaRow return err 0x00000000
Mark: was this a time that your history disappeared?

Now I just lost my history, and got:
HISTORY DEBUG: DoMore or ThumbToOpenStore returned err 0x80004005

I added some code that will set aside copies of bad history files on launch;
they will get named history_BAD.dat, history_BAD-1.dat etc. If you notice that
your history disappears (in a 2/5 build or later), please look for that file in
your profile folder, and attach a zipped copy to this bug. If you are not happy
doing that, please send it directly to me (I will be discreet). Thanks.
The error from mork when opening a "bad" history file is "duplicate alias ID".

Looking at the files, it seems that they have extra cruft at the end. This
smells to me like a problem where Mork fails to reset the EOF after doing a
commpress commit, so the file content gets smaller, but old data is left at the end.

David B., does this ring any bells?
Summary: History before yesterday disappears. → History before yesterday disappears (Mork issue?)
It seems that on a write, Mork truncates the file on open, so the bit about
cruft left at the end is not correct.

More examination of the bad files shows that we somehow end up with 2 objects in
the DB with the same mOid_Id, and from observation is seems that this is related
to history item expiration and maybe compress commits. This is almost certainly
a mork bug.
To me, that's a classic symptom of two instances of the product writing to mork
during the same session. Is that possible with Camino?
This is what I got yesterday and after that all my history data entries where gone:

HISTORY DEBUG: historyFile exists: 1

HISTORY DEBUG: OpenExistingFile(/Users/jasper/Library/Application
Support/Camino/history.dat)

HISTORY DEBUG: OpenOldFile returned err 0x00000000 (file 0x579b308)

HISTORY DEBUG: CanOpenFilePort returned err 0x00000000 (canopen 1)

HISTORY DEBUG: OpenFileStore returned err 0x00000000 (thumb 0x57b2e68)

HISTORY DEBUG: DoMore or ThumbToOpenStore returned err 0x00000000

HISTORY DEBUG: CreateTokens returned err 0x00000000

HISTORY DEBUG: GetMetaRow return err 0x00000000
The odd thing is however that my history.dat file is 1.1mb and apparently still
contains all the history data.
Yeah, that log output doesn't show anything wrong.
Some belated and probably useless info from me, but ever since I did the steps I
described in comment 10, I haven't had history disappear again.
Ok issue re-appeared in a diehard fashion.

HISTORY DEBUG: Commit() in CloseDB() returned err 0x00000000
HISTORY DEBUG: historyFile exists: 1
HISTORY DEBUG: OpenExistingFile(/Users/jasper/Library/Application
Support/Camino/history.dat)
HISTORY DEBUG: OpenOldFile returned err 0x00000000 (file 0x57fcea8)
HISTORY DEBUG: CanOpenFilePort returned err 0x00000000 (canopen 1)
HISTORY DEBUG: OpenFileStore returned err 0x00000000 (thumb 0x57fd128)
HISTORY DEBUG: DoMore or ThumbToOpenStore returned err 0x80004005
HISTORY DEBUG: removing old history file, making new one

And then this was a bit later, it might contain crap?

HISTORY DEBUG: historyFile exists: 1
HISTORY DEBUG: OpenExistingFile(/Users/jasper/Library/Application
Support/Camino/history.dat)
HISTORY DEBUG: OpenOldFile returned err 0x00000000 (file 0x5a71368)
HISTORY DEBUG: CanOpenFilePort returned err 0x00000000 (canopen 1)
HISTORY DEBUG: OpenFileStore returned err 0x00000000 (thumb 0x57a0b48)
HISTORY DEBUG: DoMore or ThumbToOpenStore returned err 0x00000000
HISTORY DEBUG: CreateTokens returned err 0x00000000
HISTORY DEBUG: GetMetaRow return err 0x00000000
/Applications/Internet/Camino.app/Contents/MacOS/Camino: can't map file:
/Library/Internet Plug-Ins/Flash Player.plugin ((os/kern) invalid argument)
HISTORY DEBUG: Commit() in CloseDB() returned err 0x00000000
HISTORY DEBUG: historyFile exists: 1
HISTORY DEBUG: OpenExistingFile(/Users/jasper/Library/Application
Support/Camino/history.dat)
HISTORY DEBUG: OpenOldFile returned err 0x00000000 (file 0x5a03b48)
HISTORY DEBUG: CanOpenFilePort returned err 0x00000000 (canopen 1)
HISTORY DEBUG: OpenFileStore returned err 0x00000000 (thumb 0x5a03dc8)
HISTORY DEBUG: DoMore or ThumbToOpenStore returned err 0x00000000
HISTORY DEBUG: CreateTokens returned err 0x00000000
HISTORY DEBUG: GetMetaRow return err 0x00000000
HISTORY DEBUG: Commit() in CloseDB() returned err 0x00000000
HISTORY DEBUG: historyFile exists: 1
HISTORY DEBUG: OpenExistingFile(/Users/jasper/Library/Application
Support/Camino/history.dat)
HISTORY DEBUG: OpenOldFile returned err 0x00000000 (file 0x5a00ce8)
HISTORY DEBUG: CanOpenFilePort returned err 0x00000000 (canopen 1)
HISTORY DEBUG: OpenFileStore returned err 0x00000000 (thumb 0x5a00f68)
HISTORY DEBUG: DoMore or ThumbToOpenStore returned err 0x00000000
HISTORY DEBUG: CreateTokens returned err 0x00000000
HISTORY DEBUG: GetMetaRow return err 0x00000000
com.apple.macosx.AntiAliasedTextOn has been deprecated. Please switch to
apple.awt.TextAntialiasing.
HISTORY DEBUG: Commit() in CloseDB() returned err 0x00000000
HISTORY DEBUG: historyFile exists: 1
HISTORY DEBUG: OpenExistingFile(/Users/jasper/Library/Application
Support/Camino/history.dat)
HISTORY DEBUG: OpenOldFile returned err 0x00000000 (file 0x5a1e588)
HISTORY DEBUG: CanOpenFilePort returned err 0x00000000 (canopen 1)
HISTORY DEBUG: OpenFileStore returned err 0x00000000 (thumb 0x5a600e8)
HISTORY DEBUG: DoMore or ThumbToOpenStore returned err 0x00000000
HISTORY DEBUG: CreateTokens returned err 0x00000000
HISTORY DEBUG: GetMetaRow return err 0x00000000
Ironically enough, it reappeared for me this afternoon, too!  (Currently using
2005021708 (v0.8+))

This is the line that,  I believe, appeared on the last quit:

HISTORY DEBUG: Commit() in CloseDB() returned err 0x00000000

And here's the logging from the launch at which history was suddenly empty folders:

HISTORY DEBUG: historyFile exists: 1
HISTORY DEBUG: OpenExistingFile(/Users/smokey/Library/Application
Support/Camino/history.dat)
HISTORY DEBUG: OpenOldFile returned err 0x00000000 (file 0x5887e78)
HISTORY DEBUG: CanOpenFilePort returned err 0x00000000 (canopen 1)
HISTORY DEBUG: OpenFileStore returned err 0x00000000 (thumb 0x5878458)
HISTORY DEBUG: DoMore or ThumbToOpenStore returned err 0x00000000
HISTORY DEBUG: CreateTokens returned err 0x00000000
HISTORY DEBUG: GetMetaRow return err 0x00000000

That last output doesn't show any errors, so I've no idea why your history is
empty. Is there a _BAD history file in your profile?

The case I'm aware of is when the printfs show:
  DoMore or ThumbToOpenStore returned err 0x80004005

No, there's not a _BAD file in my profile. Hmm.
Also have HISTORY DEBUG: Commit() in CloseDB() returned err 0x00000000
no proxy and no history.

Just to clear up some apparent confusion: An error return of zero means there
was no error.
I've finally (for the first time in 6 or 8 history losses) gotten the expected
log results (and the _BAD file):

HISTORY DEBUG: Commit() in CloseDB() returned err 0x00000000

HISTORY DEBUG: historyFile exists: 1
HISTORY DEBUG: OpenExistingFile(/Users/smokey/Library/Application
Support/Camino/history.dat)
HISTORY DEBUG: OpenOldFile returned err 0x00000000 (file 0x52325c8)
HISTORY DEBUG: CanOpenFilePort returned err 0x00000000 (canopen 1)
HISTORY DEBUG: OpenFileStore returned err 0x00000000 (thumb 0x527d778)
HISTORY DEBUG: DoMore or ThumbToOpenStore returned err 0x80004005
HISTORY DEBUG: removing old history file, making new one

Do you still want _BAD files?

Perhaps of relevance...I switched from the 21st's build to the 23rd's build
earlier tonight.
DoMore or ThumbToOpenStore returning an error is consistent with having two apps
write to the same mork file. Perhaps having some sort of lock file on disk could
help detect this. Or opening the file in some exclusive mode, but I don't think
you can do that with fopen. Since mork uses macros for all the file i/o, we
could convert it to using open and file descriptors instead of FILE *'s.
I'm 99% sure that we only every have one app writing to the mork DB, since
Camino already makes use of the profile lock. I'm also pretty sure that there is
only ever one global history service instantiated, so there should only ever be
one reader/writer.

It could be that the Camino UI is driving Mork in a way that's different, but I
don't know what that would be. It's interesting that this problem only seems to
show up after items have been expired.
Attached file error log — 
this is a debug output with errors from when my history disappeared, and the
entry before it when all was fine
Here is the output in my console from about the fifth time this bug has struck
me. Its a pretty bad one since even copying back my nightly backups of the
history file won't let me get it back. It gets rewritten or considered corrupt
every time. Anyway...

HISTORY DEBUG: historyFile exists: 1
HISTORY DEBUG: OpenExistingFile(/Users/armen/Library/Application
Support/Camino/history.dat)
HISTORY DEBUG: OpenOldFile returned err 0x00000000 (file 0x3ee93a8)
HISTORY DEBUG: CanOpenFilePort returned err 0x00000000 (canopen 1)
HISTORY DEBUG: OpenFileStore returned err 0x00000000 (thumb 0x3e33cf8)
HISTORY DEBUG: DoMore or ThumbToOpenStore returned err 0x80004005
HISTORY DEBUG: removing old history file, making new one

Hope that helps.
This may be fixed in the 3/5 build. Please try that build and post if you see
any history lossage.
3-5 or 3-6 (as it seems to take the nightlies 1-2 days before fixes show up)? 
I'm using the 3-5 nightly and just lost my history again with the same error.

HISTORY DEBUG: Commit() in CloseDB() returned err 0x00000000
HISTORY DEBUG: historyFile exists: 1
HISTORY DEBUG: OpenExistingFile(/Users/smokey/Library/Application
Support/Camino/history.dat)
HISTORY DEBUG: OpenOldFile returned err 0x00000000 (file 0x521fd98)
HISTORY DEBUG: CanOpenFilePort returned err 0x00000000 (canopen 1)
HISTORY DEBUG: OpenFileStore returned err 0x00000000 (thumb 0x1ce67b8)
HISTORY DEBUG: DoMore or ThumbToOpenStore returned err 0x80004005
HISTORY DEBUG: removing old history file, making new one

Hope this helps - Same problem - history is removed.
2005-03-07 11:44:13.085 Camino[657] JS error: Unknown property 'UserTitle'. 
Declaration dropped.
HISTORY DEBUG: Commit() in CloseDB() returned err 0x00000000
HISTORY DEBUG: historyFile exists: 1
HISTORY DEBUG: OpenExistingFile(/Users/marknewland/Library/Application
Support/Camino/history.dat)
HISTORY DEBUG: OpenOldFile returned err 0x00000000 (file 0x5539e58)
HISTORY DEBUG: CanOpenFilePort returned err 0x00000000 (canopen 1)
HISTORY DEBUG: OpenFileStore returned err 0x00000000 (thumb 0x55375e8)
HISTORY DEBUG: DoMore or ThumbToOpenStore returned err 0x00000000
HISTORY DEBUG: CreateTokens returned err 0x00000000
HISTORY DEBUG: GetMetaRow return err 0x00000000
2005-03-07 11:46:13.273 Camino[669] JS error: Selector expected.  Ruleset
ignored due to bad selector.
I just lost history in the 3-6 build, too (with the same log as before)....
Yup me to, my history also got flushed using the 6-3 nightly build. Eeek.
I'll put up an opt build with copious DB logging. Stay tuned.
I have some logging in a build in which I saw history loss. I can verify that
the is only a single mork instance when the bug occurs. The end of my mork file
looks like:


@$${39{@

<(3878=http://www.faser.net/mab/chrome/content/mab.xul)(3879
    =1110345775340526)(387A=www.faser.net)>
{1:^80 {(k^81:c)(s=9)1 } [-113A(^82^3878)(^84^3879)(^85^3879)(^88^387A)
    (^87=)]}
@$$}39}@

@$${39{@

<(3878=http://www.faser.net/mab/chrome/content/html/allinfo.html)(3879
    =1110345781377275)(387A
    =http://www.faser.net/mab/chrome/content/mab.xul)(387B=www.faser.net)
  (387C=$00C$00o$00m$00m$00e$00n$00t)(387D
    =http://www.faser.net/mab/chrome/content/html/comment.html)(387E
    =1110345781396651)>
{1:^80 {(k^81:c)(s=9)1 } [-113A(^82^3878)(^84^3879)(^85^3879)(^83^387A)
    (^88^387B)(^89=1)(^87^387C)]
  [-113B(^82^387D)(^84^387E)(^85^387E)(^83^387A)(^88^387B)(^89=1)(^87^387C)]}
@$$}39}@

@$${3A{@
{1:^80 {(k^81:c)(s=9)1 } -[-E2D]}
@$$}3A}@

@$${3A{@
{1:^80 {(k^81:c)(s=9)1 } -[-E2D]}
@$$}3A}@

which shows the duplicate alias ID (3878) and also an oddity in that some of the
groups are listed twice:

@$${39{@
@$${39{@

and

@$${3A{@
@$${3A{@

I'm pretty sure this is a mork bug.
Aha! I found a workaround, at least.

Deleting everything from the first '@$${' to the end of the file makes the
history usable again.

I have absolutely no idea if this is of any help to anyone in chasing down the
source of the bug, but it may be of use to those of us affected by it. So there
you go. :)

cl
I think I found the cause of this. If you go to about:plugins, and then make a
new tab or browser window, we load xpfe/components/nsGlobalHistory, so we then
have 2 writers to the history database.

Somehow, loading about:plugins must mess with the xpcom component registration
order, such that asking for global history gives us the xpfe one, rather than
our own.
Why is camino building the seamonkey history impl, if it's not going to use it?
Because Camino wants some of the components in xpfe/components, but not all, and
the build system doesn't have sufficient resolution to only include the ones we
want.
Sure it does...

ifneq (macbrowser,$(MOZ_BUILD_APP))
DIRS += history
endif

That's adding a requires line to the Makefile. nsModule.cpp still needs to be
#ifdeffed.
(In reply to comment #45)
> I think I found the cause of this. If you go to about:plugins, and then make a
> new tab or browser window, we load xpfe/components/nsGlobalHistory, so we then
> have 2 writers to the history database.

A couple of times I would have loaded (or attempted to load) about:plugins, but
most of the times my history has disappeared I did not load about:plugins
between the time a new history.dat was created and the time it disappeared and
made another new history.dat.  Not trying to rain on the parade; it's just the
explanation (as I understand it) of the cause doesn't match with what I've
observed :-)
RE: Comment #45

I hate to say this but, I don't think I have ever loaded about:plugins in
Camino. If I have it was so long ago that I don't remember. And it was
definitely longer ago than when I started losing my history.

Maybe it gets loaded automatically or in the background, by Camino or a plugin
that I'm not aware of, but I myself have never gone and loaed it.
Loading about:plugins is not the only way to get this to happen, just a
reproducible one. There are other actions that can cause XPCOM to reregister all
components (which is the cause of the problem).
(In reply to comment #52)
> There are other actions that can cause XPCOM to reregister all
> components (which is the cause of the problem).

Would quitting an official nightly and then opening an optimised build
(basically, two different Camino apps) be one of them?

Because that's how it always happens for me.

cl
With the nightly 2005032108 (v0.8+) Past history is removed.

2005-03-22 10:54:00.549 Camino[443] JS error: doc_els has no properties

HISTORY DEBUG: Commit() in CloseDB() returned err 0x00000000

HISTORY DEBUG: historyFile exists: 1

HISTORY DEBUG: OpenExistingFile(/Users/marknewland/Library/Application
Support/Camino/history.dat)

HISTORY DEBUG: OpenOldFile returned err 0x00000000 (file 0x1ce4268)

HISTORY DEBUG: CanOpenFilePort returned err 0x00000000 (canopen 1)

HISTORY DEBUG: OpenFileStore returned err 0x00000000 (thumb 0x55d8f18)

HISTORY DEBUG: DoMore or ThumbToOpenStore returned err 0x00000000

HISTORY DEBUG: CreateTokens returned err 0x00000000

HISTORY DEBUG: GetMetaRow return err 0x00000000

2005-03-22 10:59:52.710 Camino[467] JS error: Selector expected.  Ruleset
ignored due to bad selector.
Depends on: 286096
Fixed via bug 286096; fix will be in 3/24 nightly. Please note here if you see
history corruption with a build after this date.
Status: ASSIGNED → RESOLVED
Closed: 19 years ago
Resolution: --- → FIXED
dunno about corruption, but i hit this mork_Assertion-singla w/ a build from
sunday. otoh, i'm playing w/ multiple instances of mfcembed, so it's probably
safe to say that i asked for it.
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: