Time Machine always requires deep traversal?

Hello,

I did try the combo install. No changes.

I think I'll do a full reinstallation next week, including formatting the HDD... This will clear everything an allow to discard old applications I don't use anymore.. 😉

I'll tell you if it changes something.

Just a note, I also do a bit of programmi,ng on my mac, using Lazarus installed with Fink. I noticed that Stephen is also doing programming, maybe there is something there, don't know...

Cheers

Pierrick

Hi Stephen,

My laptop is a MacBookPro5,4. I'm running Snow leopard 10.6.8, with no partition with Lion (didn't trust it...).

Cheers

pierrick

Hi Stephen, hi Pondini,

So, I reformat my mac, and reinstalled everything. On the plus side: the computer is working much faster, I got rid of plenty of unused app! TM also is working faster and I don't get the "Node requires deep traversal:/ reason:contains changes|must scan subdirs|fsevent|" message anymore...

However, TM is still worrysome: it still takes 15 minutes to backup about 1GB, and 28 for 8GB...

Everything goes smoothly until it starts copying the files, then it takes forever (seems like anyway), with a lot of pauses in the transfer...

So all in all, it's better but still needs improvement! Any idea would be most welcome!

Cheers

Pierrick

PS: funny thing is that it always seems to backup approximatively the same amount of files see the TMBuddy message below (backup done in 16min 50 sec):

"Starting standard backup

Backing up to: /Volumes/TMSauv/Backups.backupdb

No pre-backup thinning needed: 2.65 GB requested (including padding), 125.74 GB available

Waiting for index to be ready (100)

Copied 99997 files (3.3 GB) from volume HDDmac.

No pre-backup thinning needed: 1.59 GB requested (including padding), 122.37 GB available

Copied 99996 files (37.2 MB) from volume HDDmac.

Starting post-backup thinning

No post-back up thinning needed: no expired backups exist

Backup completed successfully."

And it is quite similar for the previous backups...

Cheers

PierrickL wrote:

PS: funny thing is that it always seems to backup approximatively the same amount of files see the TMBuddy message below (backup done in 16min 50 sec):

Now that's something we've seen on a very few occasions; extremely slow backups, with very large numbers of files but small total data backed-up.

Are you running 10.6.8? If so, in some of those cases, reinstalling Snow Leopard (OSX only; not erasing anything), and installing the 10.6.7 "combo" (not going back to 10.6.8) seemed to solve it.

Very odd, but might be worth a try.

I am also having a problem with Time Machine backups taking way to long. Running 10.6.8. Incremental backups with no applications running take anywhere from 10 to 25 minutes. My guess is there is a problem with FSEvents as there are numerous directories being backed up on the increment for no reason (folders/files not modified).

For instance the following directory is backed up every hour even though the directory or the 1 file in the directory are not showing as modified. The file in the directory is not re backed up, only the directory:

/Volumes/MacintoshHD/Applications/iTunes.app/Contents/Resources/English.lproj/Ap pleTVSetup.nib

ls -le@ shows

drwxrwxr-x 3 root admin 102 Jun 22 23:55 AppleTVSetup.nib

Today is July 9 and it backs up this directory every hour.

Here are some other facts I have gathered while trying to figure out what is going on:

• Incremental backup took 11 minutes

• No applications were running

• load average .18 (before backupd started running)

• Spotlight disabled on TM backup drive

• Only 3 other backup sets existed on backup drive

• Total new items backed up 7911

7136 were directories

70 actual files

705 symlinks

• Total MB backed up: 7.43

• Lots of Directories being backed up incrementally even though modification date does shows much earlier than even the first backup.

Are there any command line tools to query FSEvents?

B

I hacked up a perl script to analyze the TM backup sets. Outputs the following:

The perl code is a bit of a mess but here it is:

#! /usr/bin/perl -w

use strict;

#### 1.1 now using perl's lstat instead of backticks.

#### 1.2 Will compare all directories in Backups.backupdb.

#### 1.3 Trim down @laterListing after building to save memory.

#### 1.4 Store each index in a zip file on disk to save RAM and have something to reference later.

#### 1.5 Added support for spaces in file paths.

#### 1.6 added columns for file type, mode ctime for backup file and ORIGINAL mtime ctime bytes and file name

#### 1.6 added columns for file type, mode and ctime

#### Define global variables.

my $scriptName = "compareTMdirectories-1.6.pl";

my $outputDirectory = "$ENV{HOME}/Desktop/FolderCatalogs";

print "Running $scriptName at " . `date`;

die "Specify root folder. IE'/Volumes/LaCie1TB/Backups.backupdb/rmbp'\n" unless $ARGV[0];

my $rootFolder = "$ARGV[0]";

die "That is not a folder.\n" unless (-d $rootFolder) ;

$rootFolder =~ s/ /\\ /g;

$rootFolder =~ s/\/$//;

#### Create output Directory. Here is where we will write text files.

unless (-d "$outputDirectory") {

mkdir "$outputDirectory";

}

sleep 1;

die "Could not create output directory '$outputDirectory'.\n" unless (-d "$outputDirectory");

#### Look in directory specified at run time and get list of dirs to search.

my @dirList = glob "$rootFolder/*";

## Escape spaces in full path and file name

#for (@dirList) { s/ /\\ /g; }

#print "$rootFolder\n";

#print @dirList;exit;

#### Build an index of each TM backup set.

## Loop (in reverse order) through list of directories from glob.

## Build index file of each dir in glob, outputting to .Z.

my $i = scalar(@dirList)-1;

while ($i >= 0) {

my $dirToIndex = $dirList[$i];

$i = $i - 1;

#print "'$dirToIndex'\n";

next if ($dirToIndex =~ /Latest/); ## Ignore Latest symlink.

#next if (-e "$dirToIndex"); ## If index already exists, do not reindex, skip to next one.

#$dirToIndex =~ s/ /\\ /g;

#### Retrieve top level directory name to use for title of .Z output file.

my $dirIndex = returnFileName($dirToIndex);

$dirIndex .= ".Z";

## Add volume name to file name in order to differentiate between different TM volumes.

my $bupSetNamePrepend = $dirToIndex;

my @pathSegments = split /\//, $bupSetNamePrepend;

$bupSetNamePrepend = $pathSegments[2];

$dirIndex = "$bupSetNamePrepend-$dirIndex";

# print "'$dirToIndex' '$dirIndex' \n";

#print "'$outputDirectory/$dirIndex'\n";

#next;

## Check to see if output index file exists

if (-e "$outputDirectory/$dirIndex") {

print "Output file '$outputDirectory/$dirIndex' already exists. Skipping find on $dirToIndex\n";

} else {

my $findExec = "find -x \"$dirToIndex\" -ls | gzip --best - > \"$outputDirectory/$dirIndex\"";

print "Indexing using '$findExec'\n";

my $timerStart = time;

system ($findExec) == 0 || die "Could not find.\n";

my $elapsedTime = time - $timerStart;

$elapsedTime = sprintf "%.2f", $elapsedTime / 60;

print "Index of $dirToIndex took $elapsedTime minutes.\n";

#undef $timerStart,$elapsedTime;

#open (OUTPUTHANDLE, ">", "$outputDirectory/$bupSetName") or die "Failed to create output file \"$outputDirectory/$bupSetName\".\n";

}

#### Get list of all index files and compare later to earlier.

my @zList = glob "$outputDirectory/*.Z";

## Escape spaces in file name.

for (@zList) { s/ /\\ /g; }

my $i = scalar(@zList)-1;

while ($i > 0) {

my $later = $zList[$i];

$i = $i - 1;

my $earlier = $zList[$i];

my $compareFileName = returnFileName($later) ."_" . returnFileName($earlier) . ".txt";

next if (-e "$compareFileName");

print "Comparing\n";

my $timerStart = time;

$compareFileName =~ s/\\ / /g;

&compareFolderIndexes($later,$earlier,$compareFileName);

my $elapsedTime = time - $timerStart;

$elapsedTime = sprintf "%.2f", $elapsedTime / 60;

print "Compare time was $elapsedTime minutes.\n\n";

}

}

exit;

################################################################################ ###########

## Subroutines below, used in above.

sub returnFileName {

#### Retrieve directory name to use for title of output file.

my $fullPath = $_[0];

$fullPath = reverse($fullPath);

$fullPath =~ s/\/.+$//;

$fullPath = reverse($fullPath);

return $fullPath;

}

sub compareFolderIndexes {

## Get files to compare.

my $later = $_[0];

my $earlier = $_[1];

my $bupSetName = $_[2];

if (-e "$outputDirectory/$bupSetName") {

#print "File exists, skipping '$outputDirectory/$bupSetName'\n";

return;

}

print "Comparing $later to $earlier.\n";

open(COMPAREHANDLE, ">", "$outputDirectory/$bupSetName") or die "Could not open output file '$outputDirectory/$bupSetName'\n";

print COMPAREHANDLE "rowCounter\tinode\ttype\tmode\tmtime\tctime\tbytes\tMBytes\tfilenameOnBackup\t originalMtime\toriginalCtime\toriginalB\toriginalMB\toriginalFile\n";

#### Get hash of inodes in earlier directory.

my %earlierHash;

open(EARLIERHANDLE, "-|", "zcat $earlier");

while (<EARLIERHANDLE>) {

m/(\d+)/;

$earlierHash{$1} = 1;

#print $1 . "\n";

}

close(EARLIERHANDLE);

print "hash built\n";

#### Read though later index and see if we match any inodes to earlierHash.

open(LATERHANDLE, "-|", "zcat $later") or die "Could not open $later.\n";

my $rowCounter;

while (<LATERHANDLE>) {

s/^\s+//;

m/^(\d+).+? (\/.+$)/;

my $laterInode = $1;

my $laterFileName = $2;

## Remove symlink verbage from find -ls output

$laterFileName =~ s/( -> .+$)//;

#my $laterLine = "$laterInode\t$laterFileName";

if ($earlierHash{$laterInode}) {

} else {

$rowCounter ++;

#print "statting $laterFileName\n";

my (undef,$ino,$mode,undef,undef,undef,undef,$size,undef,$mtime,$ctime,undef,undef ) = lstat($laterFileName);

my $sizeMB = $size / 1000000;

## Format mtime.

my ($sec,$min,$hour,$mday,$mon,$year,undef,undef,undef) = localtime($mtime);

$year += 1900;

$mon += 1;

if ($mon =~ /^\d$/) {$mon = "0$mon"};

if ($mday =~ /^\d$/) {$mday = "0$mday"};

if ($hour =~ /^\d$/) {$hour = "0$hour"};

if ($min =~ /^\d$/) {$min = "0$min"};

## Format ctime.

my ($secC,$minC,$hourC,$mdayC,$monC,$yearC,undef,undef,undef) = localtime($ctime);

$yearC += 1900;

$monC += 1;

if ($monC =~ /^\d$/) {$monC = "0$monC"};

if ($mdayC =~ /^\d$/) {$mdayC = "0$mdayC"};

if ($hourC =~ /^\d$/) {$hourC = "0$hourC"};

if ($minC =~ /^\d$/) {$minC = "0$minC"};

## Get mode into TYPE and MODE.

my $type = substr $mode, 0, 1;

$mode =~ s/^\d//;

if ($type eq "1") {$type = "d";}

if ($type eq "3") {$type = "f";}

if ($type eq "4") {$type = "l";}

my $laterFileStat = "$rowCounter\t$ino\t$type\t$mode\t$year-$mon-$mday-$hour$min\t$yearC-$monC-$mda yC-$hourC$minC\t$size\t$sizeMB\t$laterFileName";

## Repeat stat on original file name. (Redundant code I know)

my $originalFileName = $laterFileName;

$originalFileName =~ s/^\/Volumes\/(.*?)\/(.*?)\/(.*?)\/(.*?)\//\/Volumes\//;

## First check to see if file exists.

if (-e "$originalFileName") {

(undef,$ino,$mode,undef,undef,undef,undef,$size,undef,$mtim e,$ctime,undef,undef) = lstat($originalFileName);

$sizeMB = $size / 1000000;

## Format mtime.

($sec,$min,$hour,$mday,$mon,$year,undef,undef,undef) = localtime($mtime);

$year += 1900;

$mon += 1;

if ($mon =~ /^\d$/) {$mon = "0$mon"};

if ($mday =~ /^\d$/) {$mday = "0$mday"};

if ($hour =~ /^\d$/) {$hour = "0$hour"};

if ($min =~ /^\d$/) {$min = "0$min"};

## Format ctime.

($secC,$minC,$hourC,$mdayC,$monC,$yearC,undef,undef,undef) = localtime($ctime);

$yearC += 1900;

$monC += 1;

if ($monC =~ /^\d$/) {$monC = "0$monC"};

if ($mdayC =~ /^\d$/) {$mdayC = "0$mdayC"};

if ($hourC =~ /^\d$/) {$hourC = "0$hourC"};

if ($minC =~ /^\d$/) {$minC = "0$minC"};

if ($type eq "4") {$type = "l";}

## Get mode into TYPE and MODE.

$type = substr $mode, 0, 1;

$mode =~ s/^\d//;

if ($type eq "1") {$type = "d";}

if ($type eq "3") {$type = "f";}

$laterFileStat = $laterFileStat . "\t$year-$mon-$mday-$hour$min\t$yearC-$monC-$mdayC-$hourC$minC\t$size\t$sizeMB\ t$originalFileName";

}

print COMPAREHANDLE $laterFileStat;

print COMPAREHANDLE "\n";

}

}

print COMPAREHANDLE "Completed compare of $later to $earlier at " . `date`;

print COMPAREHANDLE "EOF";

close(COMPAREHANDLE);

close(LATERHANDLE);

#exit;

}

TM stores the last event number (and event store UUID) it used for the last backup to each TM drive. I don't know just where it is, but it appears to be somewhere on the TM drive, perhaps as extended attributes on each date-stamped backup folder, not the OSX volume.