QRecallDownloadIdentity KeysForumsSupport
  [Search] Search   [Recent Topics] Recent Topics   [Hottest Topics] Hottest Topics   [Groups] Back to home page 
Messages posted by: Frederic Thomas
Forum Index » Profile for Frederic Thomas » Messages posted by Frederic Thomas
Author Message
Did you get the logs? I'm just asking since I did not get a reply from you and it was a 5.x MBytes email...

Also I am trying capturing something from OS X now, the volume that was giving us trouble.

Fred
OK

My problem is (a) at some point I really need a working system and (b) disk space becomes a problem running multiple systems in parallel.

So I had to use the backup disk space for a working backup with Retrospect and had to delete the old archive: not easy to move around 250GB...

Kept all the log files, sending them now.

I am not sure I understood what test you'd like me to perform: OS X Server stuff on a OS X server only archive ? (even a local one?)

Fred
OK, so here's the log on the machine that repaired the archive:

2007-10-26 17:59:04.427 +0200 ------- Repair imac24.quanta [2.732975.15361]

...

2007-10-27 02:48:16.927 +0200 #debug# sorting 3448877 hash entries [2.732975.15361.16]
2007-10-27 02:48:38.837 +0200 #debug# writing 3448877 new hash entries, flushing 0 [2.732975.15361.18]
2007-10-27 02:58:10.340 +0200 #debug# hash contains 11837484 entries [2.732975.15361.19]
2007-10-27 02:58:10.420 +0200 #debug# -[DataHash closeNegativeHashMap] writing RAM map to file; size 67108864, path /Volumes/RetroCPQrec/imac24.quanta/negative.index [2.732975.15361.20]
2007-10-27 02:58:11.309 +0200 #debug# -[NegativeChecksumMap writeMapFileAtPath:] wrote 8388612 bytes to /Volumes/RetroCPQrec/imac24.quanta/negative.index, result=YES, trues=10852949 [2.732975.15361.21]
2007-10-27 02:58:12.958 +0200 #debug# FillMap: 70047 holes, 22960968 free (22960968 clean, 0 trashy) [2.732975.15361.22]
2007-10-27 02:58:13.870 +0200 #debug# -[NegativeChecksumMap dealloc] released, 67108864 bits, 10852949 trues [2.732975.15361.23]
2007-10-27 02:58:13.996 +0200 ------- Repair finished (8:59:0 [2.732975.15361.24]


Note it says "REPAIR COMPLETE". But apparently I just waited a 8 hours of my life for nothing, as capturing again:

2007-10-27 03:52:32.259 +0200 ------- Capture to imac24.local.quanta [2.732976.488]
2007-10-27 03:52:32.259 +0200 Details archive: /Volumes/RetroCPQrec/imac24.local.quanta [2.732976.488.5]
2007-10-27 03:52:32.259 +0200 #debug# executing [2.732976.488.6]
2007-10-27 03:52:32.260 +0200 #debug# -[RepositoryCommand prepareRepositoryUsing:] alias reference invalid, path RetroCPQrec:imac24.local.quanta [2.732976.488.7]
2007-10-27 03:52:32.261 +0200 #debug# -[RepositoryCommand prepareRepositoryUsing:] no listeners that will resolve alias [2.732976.488.8]
2007-10-27 03:52:32.761 +0200 #debug# -[ProgressManager resolveReferenceRequest:] RetroCPQrec:imac24.local.quanta [4.732976.477.4]
2007-10-27 03:52:32.762 +0200 #debug# -[ProgressManager _resolveReference:] RetroCPQrec:imac24.local.quanta [4.732976.477.5]
2007-10-27 03:52:32.762 +0200 #debug# -[RepositoryCommand prepareRepositoryUsing:] requested resolution; waiting for results [2.732976.488.9]
2007-10-27 03:52:33.739 +0200 #debug# -[DiskArbitrationSteward volumeMountNotification:] mounted volume /Volumes/RetroCPQrec [3.732976.485.8]
2007-10-27 03:52:33.771 +0200 #debug# discovered recent 'imac24.quanta', mod=2007-10-24 22:52:12 +0200, repository=/Volumes/RetroCPQrec/imac24.quanta [4.732976.477.6]
2007-10-27 03:52:33.773 +0200 #debug# -[RepositoryCommand didResolveRepositoryRef] [2.732976.488.10]
2007-10-27 03:52:33.899 +0200 #debug# -[NegativeChecksumMap initMappedToPath:] mapped to /Volumes/RetroCPQrec/imac24.quanta/negative.index, 8388608 bytes, 67108864 bits, 10852949 trues [2.732976.488.11]
2007-10-27 03:52:33.899 +0200 #debug# -[DataHash loadNegativeHashMap] discovered existing map; size 67108864, path /Volumes/RetroCPQrec/imac24.quanta/negative.index [2.732976.488.12]
2007-10-27 03:52:33.902 +0200 #debug# -[NegativeChecksumMap dealloc] unmapped/closed, 67108864 bits, 10852949 trues [2.732976.488.13]
2007-10-27 03:52:33.905 +0200 #debug# -[DataHash loadNegativeHashMap] alloc empty map; size 1073741824 [2.732976.488.14]
2007-10-27 03:52:34.127 +0200 #debug# -[NegativeChecksumMap initWithCapacity:] in memory, 134217732 bytes, 1073741824 bits, 0 trues [2.732976.488.15]
2007-10-27 03:52:37.789 +0200 #debug# terminating Client-1.0.0b(4-Oct 21 2007 [1.732976.472.22]
2007-10-27 03:53:00.862 +0200 #debug# -[QRUserBSDSocketPath connectPort] /var/tmp/QRecall.501/QRecallScheduler [3.732976.492.1]
2007-10-27 03:53:02.365 +0200 #debug# QuantumScheduler exiting with status 0 [3.732976.492.2]
2007-10-27 03:55:06.206 +0200 #debug# -[DataHash loadNegativeHashMap] rebuilt negative map from hash; refill=YES, 11772756 trues, 11837485 cached entries [2.732976.488.16]
2007-10-27 03:55:06.208 +0200 #debug# -[HashFile anticipateHashGrowth:] total free=321586511872, practicalGrowth=11776849, maxGrowth=21716947, hashEntries=11837484, hashSize=134217728 [2.732976.488.17]
2007-10-27 03:55:06.208 +0200 #debug# growth of 11776849 entries will not cause hash to exceed 134217728 entries [2.732976.488.18]
2007-10-27 03:59:00.515 +0200 #debug# -[QRUserBSDSocketPath connectPort] /var/tmp/QRecall.501/QRecallScheduler [3.732976.511.1]
2007-10-27 03:59:02.016 +0200 #debug# QuantumScheduler exiting with status 0 [3.732976.511.2]
2007-10-27 04:12:14.599 +0200 #debug# -[NegativeChecksumMap dealloc] released, 1073741824 bits, 11772756 trues [2.732976.488.19]
2007-10-27 04:12:14.640 +0200 Failure Failed [2.732976.488.20]
2007-10-27 04:12:14.640 +0200 Details invalid envelope type [2.732976.488.20.1]
2007-10-27 04:12:14.640 +0200 Details Data exception [2.732976.488.20.1.1]
2007-10-27 04:12:14.640 +0200 Details Length: 766761 [2.732976.488.20.1.2]
2007-10-27 04:12:14.640 +0200 Details Type: 1644167168 [2.732976.488.20.1.3]
2007-10-27 04:12:14.640 +0200 Details Pos: 213911357848 [2.732976.488.20.1.4]
2007-10-27 04:12:14.640 +0200 #debug# Caught exception [2.732976.488.21]
2007-10-27 04:12:14.641 +0200 Details invalid envelope type [2.732976.488.21.1]
2007-10-27 04:12:14.641 +0200 Details Data exception [2.732976.488.21.1.1]
2007-10-27 04:12:14.641 +0200 Details Length: 766761 [2.732976.488.21.1.2]
2007-10-27 04:12:14.641 +0200 Details Type: 1644167168 [2.732976.488.21.1.3]
2007-10-27 04:12:14.641 +0200 Subrosa .Command: capture [2.732976.488.21.1.4]
2007-10-27 04:12:14.641 +0200 Details Pos: 213911357848 [2.732976.488.21.1.5]
2007-10-27 04:12:14.641 +0200 Capture failed [2.732976.488.22]
2007-10-27 04:12:14.641 +0200 A data integrety problem in the archive was encountered. Consider reindexing or repairing the archive. [2.732976.488.22.1]
2007-10-27 04:12:14.641 +0200 ------- Capture incomplete (17:07) [2.732976.488.23]

Fred




Also, I've now spent about 48 hours reindexing and repairing the archive but it still fails to backup to it (the computer that used to work).

Once you have 2-3 machines having N drives all backuping to the same shared archive, changing the archive everytime Qrecall thinks it has a problem is a pain.

I *still* think the archives are too fragile. Something goes wrong and boom, there goes your archive.

Fred
James Bucanek wrote:In the mean time, I'd consider reinstalling the OS on that computer.


Huh ? I mean, it works fine - sounds very drastic. And it did capture 250GB all right. Just in case, it's Mac OS X SERVER, if that makes any difference?

I have rebooted the machine and will try again the capture on a new archive.

Fred
So... It worked fine for a while: single mac capturing things to an archive. It does it at the scheduled time (or later). It mounts the network volume. Fine.

So next step was to backup another machine on the same volume/archive. Got another key. 3 volumes to capture.

Only thing is the captures this time are huge, 200+ GB... and so it takes a while to perform, but they are all scheduled at the same time.

The first capture eventually finished. The second stopped because "there was not enough memory". The third dutifully waited until the first finished... only to stop with an archive integrity error. On the other mac, the backup waited for the third capture to fail to fail as well. So the archive is being repaired as we speak.

I have a log file of 69 MB which mainly contains endless repetitions of (the file changes, of course):

2007-10-25 21:56:39.110 +0200 Curious No file icon [2.732974.25150.18.9]
2007-10-25 21:56:39.110 +0200 Details missing file icon [2.732974.25150.18.9.1]
2007-10-25 21:56:39.110 +0200 Details IO exception [2.732974.25150.18.9.1.1]
2007-10-25 21:56:39.111 +0200 Details File: System:Libraryrinters:EPSON:LaserPrinter:CommonageLibraries:usbepson.framework:Versions:A:usbepson [2.732974.25150.18.9.1.2]
2007-10-25 21:56:39.111 +0200 Curious No folder icon [2.732974.25150.18.10]
2007-10-25 21:56:39.111 +0200 Details missing folder icon [2.732974.25150.18.10.1]
2007-10-25 21:56:39.111 +0200 Details IO exception [2.732974.25150.18.10.1.1]
2007-10-25 21:56:39.111 +0200 Details Folder: System:Libraryrinters:EPSON:LaserPrinter:CommonageLibraries:usbepson.framework:Versions:A [2.732974.25150.18.10.1.2]
2007-10-25 21:56:39.115 +0200 Curious Could not obtain icon [2.732974.25150.30]
2007-10-25 21:56:39.115 +0200 Details error obtaining icon [2.732974.25150.30.1]
2007-10-25 21:56:39.116 +0200 Details IO exception [2.732974.25150.30.1.1]
2007-10-25 21:56:39.116 +0200 Details File: Current [2.732974.25150.30.1.2]
2007-10-25 21:56:39.116 +0200 #debug# API: GetIconRefFromFileInfo [2.732974.25150.30.1.3]
2007-10-25 21:56:39.116 +0200 #debug# OSErr: -2582 [2.732974.25150.30.1.4]
2007-10-25 21:56:39.117 +0200 Curious No file icon [2.732974.25150.18.11]
2007-10-25 21:56:39.118 +0200 Details missing file icon [2.732974.25150.18.11.1]
2007-10-25 21:56:39.118 +0200 Details IO exception [2.732974.25150.18.11.1.1]
2007-10-25 21:56:39.118 +0200 Details File: System:Libraryrinters:EPSON:LaserPrinter:CommonageLibraries:usbepson.framework:Versions:Current [2.732974.25150.18.11.1.2]
2007-10-25 21:56:39.119 +0200 Curious No folder icon [2.732974.25150.18.12]
2007-10-25 21:56:39.119 +0200 Details missing folder icon [2.732974.25150.18.12.1]
2007-10-25 21:56:39.119 +0200 Details IO exception [2.732974.25150.18.12.1.1]
2007-10-25 21:56:39.119 +0200 Details Folder: System:Libraryrinters:EPSON:LaserPrinter:CommonageLibraries:usbepson.framework:Versions [2.732974.25150.18.12.1.2]
2007-10-25 21:56:39.122 +0200 Curious Could not obtain icon [2.732974.25150.31]
2007-10-25 21:56:39.122 +0200 Details error obtaining icon [2.732974.25150.31.1]
2007-10-25 21:56:39.122 +0200 Details IO exception [2.732974.25150.31.1.1]
2007-10-25 21:56:39.123 +0200 Details File: Resources [2.732974.25150.31.1.2]
2007-10-25 21:56:39.123 +0200 #debug# API: GetIconRefFromFileInfo [2.732974.25150.31.1.3]
2007-10-25 21:56:39.124 +0200 #debug# OSErr: -2582 [2.732974.25150.31.1.4]

and finishes with

2007-10-25 22:50:25.448 +0200 Curious No file icon [2.732974.25150.18.75470]
2007-10-25 22:50:25.448 +0200 Details missing file icon [2.732974.25150.18.75470.1]
2007-10-25 22:50:25.448 +0200 Details IO exception [2.732974.25150.18.75470.1.1]
2007-10-25 22:50:25.448 +0200 Details File: System:var [2.732974.25150.18.75470.1.2]
2007-10-25 22:50:25.514 +0200 #debug# -[DataHash preloadHashCache] stopped [2.732974.25150.75488]
2007-10-25 22:51:12.999 +0200 #debug# -[NegativeChecksumMap dealloc] unmapped/closed, 536870912 bits, 11708025 trues [2.732974.25150.75489]
2007-10-25 22:51:13.064 +0200 Failure Failed [2.732974.25150.75490]
2007-10-25 22:51:13.064 +0200 Details error getting generic folder icon [2.732974.25150.75490.1]
2007-10-25 22:51:13.064 +0200 Details NSInternalInconsistencyException exception [2.732974.25150.75490.1.1]
2007-10-25 22:51:13.066 +0200 Failure Program exception [2.732974.25150.75491]
2007-10-25 22:51:13.068 +0200 Details error getting generic folder icon [2.732974.25150.75491.1]
2007-10-25 22:51:13.069 +0200 Details NSInternalInconsistencyException exception [2.732974.25150.75491.1.1]
2007-10-25 22:51:13.069 +0200 Command failed [2.732974.25150.75492]
2007-10-25 22:51:13.069 +0200 An internal program error occurred. Please report this problem to the developer. [2.732974.25150.75492.1]
2007-10-25 22:51:13.070 +0200 ------- Capture incomplete (1:23:20) [2.732974.25150.75493]
2007-10-25 22:51:13.081 +0200 #debug# command returned exception [4.732974.17469.9]
2007-10-25 22:51:13.081 +0200 Details error getting generic folder icon [4.732974.17469.9.1]
2007-10-25 22:51:13.081 +0200 Details NSInternalInconsistencyException exception [4.732974.17469.9.1.1]
2007-10-25 22:51:13.083 +0200 #debug# command returned exception [3.732974.17499.39]
2007-10-25 22:51:13.083 +0200 Details error getting generic folder icon [3.732974.17499.39.1]
2007-10-25 22:51:13.084 +0200 Details NSInternalInconsistencyException exception [3.732974.17499.39.1.1]
2007-10-25 22:51:13.093 +0200 #debug# stopped [2.732974.25150.75494]
2007-10-25 22:51:19.094 +0200 #debug# CaptureCommand has no listeners, terminating process [2.732974.25150.75495]
2007-10-25 22:51:20.120 +0200 #debug# -[QRUserBSDSocketPath deleteSocket] /var/tmp/QRecall.501/QRecallHelper.243c9869 [2.732974.25150.75496]
2007-10-25 22:59:01.586 +0200 #debug# -[QRUserBSDSocketPath connectPort] /var/tmp/QRecall.501/QRecallScheduler [3.732974.25207.1]
2007-10-25 22:59:03.102 +0200 #debug# QuantumScheduler exiting with status 0 [3.732974.25207.2]

Need the log ? It's only 5.4 MB zipped. Or I can cut the middle stuff.

Fred
Attaching here the crashlog, the forum SW seems to be a bit flaky when it comes to attachements.

Also, after re-reading the release notes, maybe I should mention the directory ~/Programs/Temp/html contains 42'110 items.
James Bucanek wrote:
Frederic Thomas wrote:Another wrong guess

It's not a guess.

I meant from attributing it to network volumes.

Does this error occur every time you try to capture this volume/folder, or has it only occurred while the directories were being modified at the same time? Another good question to get out of the way: Is this the same error you've received in the past, or is this the first time it's occurred?


I've had a similar error (archive ends up corrupted after 1-2 days) everytime I have tried to use QRecall to backup my machines on network volumes.

If this error is consistent, try capturing and recapturing the volume/folder with the latest version and let me know how that works.


Initial capture went OK (with new version). Trying a second one to check now (so the attached log will contain a partial capture at the end).


I also noticed a couple of other odd things in your log file. Could you check your ~/Library/Logs/CrashReporter/ folder for any recent crash logs?


Attached.

Could you also verify that you have only once instance of the QRecallScheduler process running?


imac24:~ fred$ ps -ax | grep QRecall
278 ?? S 0:00.22 /Applications/QRecall.app/Contents/Resources/QRecallMonitor.app/Contents/MacOS/QRecallMonitor -psn_0_2097153
337 ?? S 0:00.08 /Users/fred/Library/Application Support/QRecall/QRecallScheduler
828 p1 S+ 0:00.00 grep QRecall


That said, upgrading to the new version did not happen smoothly, see attached log. QRecall kept on complaining about the scheduler not being the same version, or something. Seems OK now. Given it was beta to beta upgrade and I was chasing the other problem, I did not pay too much attention...
>The problem reported in your log file doesn't have
>anything to do with network volumes.

Another wrong guess

>make those commands

Here you go:

imac24:~ fred$ ls -A1 /Users/fred/Programs
.DS_Store
Godot
Internal
Lopez
Temp
WebKit
bin
lua-5.1.2

imac24:~ fred$ ls -A1 /Users/fred/Programs/Temp
.DS_Store
calimero-1.4
html
mh
pvb
webcore - Doxyfile
imac24:~ fred$


Note that these directories contain svn things that do change quite a bit, potentially even during captures. I may also have moved things.

Thanks

Fred
I am starting to think there's a major issue with QRecall and network volumes. I just can't get it to work reliably. I've changed client and server. Everytime the archive ends up corrupted.

Here's the log of my last attempt. I will give it yet another try with the latest version!
James Bucanek wrote:QRecall found approximately 2 MB of damaged data. The other 99.992% of 12.4GB is just fine.


Then I guess some reserve may be needed when such an archive is displayed after "repair": -damaged- was written all over it.

Is this archive new or have you been using it for some time?


New. The first capture did not finish.

What were the actions (if any) leading up to the one that failed?


Nothing manual. I started a capture of the entire disk on a remote volume. It never finished. The machine may have slept.

Where is the archive stored? Are there other files/archives on this volume and are they OK?


OS X Server afp:// share. 288GB used out of 400 GB. After this I did run DU on it as you suggested and it repaired the volume header. As far as I can tell, all files are OK on the volume.

Note that I did try to backup on a volume mounted by an Airport Extreme and also had strange issues (see other thread). I am only mentioning it because it's again a strange issue associating QRecall and network mounted volumes (which seem to work OK for everything else).

When you repaired the archive, did you tell QRecall to recover incomplete files?


Nope, there is an option about making a copy that I did not select. I only did the backup to test QRecall in the first place. It did not capture the entire volume. So there was little value in recovering the archive.

Hope this helps!

Fred

James Bucanek wrote:It shouldn't have any problems. A virtual machine is just another file as far as QRecall is concerned.


That's what I thought.

run disk utility on your volume


Volume header problem - fixed.

Try repairing the archive and see what happens.


Log attached. Pretty much 22GB of useless junk.

Fred
Hello,

Does QRecall have a problem with virtual machines? See attached log, the Parallels machine fails to backup.

On a side note it would be best if one failed file did not stop the entire backup...


Dunno. Here's the log.
Hello,

Using the new QRecall on a new network archive, I have tried twice to back up a 80+ GB MacBook Pro but each time the machine goes to sleep, and then, when waking up, all hell breaks loose for QRecall. Incomplete backup, damaged archive (reindexing fails), ...

In this state QRecall is basically useless. Bug? Flaw? Other problem of my machine ?

Thanks




 
Forum Index » Profile for Frederic Thomas » Messages posted by Frederic Thomas
Go to:   
Powered by JForum 2.1.8 © JForum Team