MFT/directories 'jerking'

[ff_mfg]

First noticed in 4.2.7, kinda hoped it would go away in 4.2.8... sadly, no

Of the 5 volumes I regularly defragment with MyDefrag I encounter this on only one. _Every_ time defragmentation starts with either MFT of a chunk of sorted directories being moved away and then returned exactly at the same place. If MTF jumps, directories are not touched. If MFT stays, a part of directories 'jumps' (I know the dirs return exactly to the same location because disk has a lot of files and a lot of directories. After some dirs got moved the rest is skipped, and if there were even small shift, the whole structure would be moved (SortBy is used), and it's a long process on that disk...). Which one got moved seem to depend on the placement: when MFT/dirs were at the start, MFT were moved, now I've tried the default (30% used) - MFT stays, dirs moved.
I have to notice - these moves occur even if there are 0 changes to the disk between defragmentation runs.
Should I run with debug? Which level?

edit:
Actually... Now I see the same happening with directories on other volumes. I think it wasn't so in 4.2.7.

[jeroen]

This is not a bug. The MFT and the directories change a lot, and will therefore almost always be moved by SortBy(). There are some tricks to reduce this behavior (for example by adding a gap after the MFT, or by using FastFill instead of SortBy), but those are not possible at the moment in combination with the 30% into-the-data zone.

[ff_mfg]

Look, I realize my rants are little hard to read, but please make an effort I'm trying to help improve MyDefrag.

The MFT and directories do not change at all between runs. This is not a system volume and no background processes access it. Usually when MyDefrag runs the second time on unchanged disk it justs analyzes the disk and find everything already sorted and quickly finishes. Not on volumes with this problem...

And now I think I understand why the described is happening. The volumes where the problem appear have a number of unmovable NTFS system files. For example this one I'm mostly testing on has a bunch of filename::$ATTRIBUTE_LIST entries. I've looked them up, they are leftovers from a bunch of big hugely fragmented files, NTFS uses those $ATTRIBUTE_LIST when fragment lists are deemed to big for MFT itself. Those files are defragmented now, and I don't really understand why these are left hanging or why they are unmovable (btw, they are not listed in unmovables list or mydefrag.dat, but they are red on the map; there might be more such unlisted unmovables).

My guess is that MyDefrag tries to move these filesystem files next to MFT (I can see on the map some system files go after MFT and reserved zone, such as $Secure, $Extend and $UpCase), and this place is occupied by directories. MyDefrag frees up the space by moving directories. Then it tries to move those unmovables, fails, finishes with the zone 1, proceeds to zone 2-directories - and by sorting returns those moved directories back.
In the case where MFT gets moved my guess is that the unmovable filesystem files go before MFT in sorting order.

I'll try to produce meaningful debug log now...

Code:

...
13:41:09 Processing disk S:
13:41:09   Cleaning up old data from memory.
13:41:09     Finished cleaning up old data from memory.
13:41:09   Starting to analyze volume 'S:' (\\?\Volume{bfb200c0-ad0f-11de-aaa2-806d6172696f})
13:41:09     NTFS reserved area: from 18125728 to 18132960 (7232 clusters).
13:41:09     This is an NTFS disk.
13:41:09     Disk cookie: 202020205346544E
13:41:09     TotalClusters: 82062028
13:41:09     BytesPerClusters: 4096
13:41:09     TotalSectors: 656496224
13:41:09     BytesPerSector: 512
13:41:09     SectorsPerCluster: 8
13:41:09     SectorsPerTrack: 63
13:41:09     NumberOfHeads: 255
13:41:09     MftStartLcn: 4
13:41:09     Mft2StartLcn: 41031014
13:41:09     BytesPerMftRecord: 1024
13:41:09     ClustersPerIndexRecord: 1
13:41:09     MediaType: F8
13:41:09     VolumeSerialNumber: 66D8811D5CD9ED8C
13:41:39     Analysis speed: 9681 items per second
13:41:39     Getting fragment list for: S:\$MFT
13:41:39       Extent: Lcn=4, Vcn=0, NextVcn=4
13:41:39       Extent: Lcn=18053647, Vcn=4, NextVcn=72088
13:41:39       Translating into fragment tree....
13:41:39       Counting fragments....
13:41:39     Hiding the virtual clusters of: S:\$BadClus:$Bad:$DATA
13:41:39     Finished analyzing the volume.
13:41:39     Calculating the maximum end of the gap.
13:41:39       Number of clusters in remaining items: 57184428
13:41:40       Iteration 1: 2 unmovable clusters after 24877600, new ZoneBegin = 24877598
13:41:40       Iteration 2: 2 unmovable clusters after 24877598, new ZoneBegin = 24877598
13:41:40       Maximum end of gap = 24877598
13:41:40     Statistics before:
  Total disk space:     336 126 066 688 bytes
  Unfragmented items:   230 396 973 056 bytes           287 859 items
  Fragmented items:       3 830 484 992 bytes                 2 items
  Gaps:                 101 898 592 256 bytes                39 gaps
  Average gap:            2 612 781 056 bytes
  Median gap:                 2 740 224 bytes
  Biggest gap:           72 690 089 984 bytes
13:41:40   Loading list of unmovable files
13:41:40     Processing: 'S:\$MFT::$BITMAP'
13:41:40       Looking for the first gap of at least 9 clusters after Lcn=0.
13:41:40         Gap found: Lcn=4867119, Size=380881
13:41:40       Moving 'S:\$MFT::$BITMAP'
13:41:40         Could not open: [2] The system cannot find the file specified.
13:41:40         Changing the item into 'not movable'.
13:41:40         Calculating the end of the zone.
13:41:40           ZoneBegin = 0
13:41:40           Number of clusters in selected items = 0
13:41:40           Iteration 1: 0 unmovable clusters between 0 and 0, ZoneEnd = 0
13:41:40           Re-using old ZoneEnd: 0
13:41:40       File is unmovable: 'S:\$MFT::$BITMAP'
13:41:40     Processing: 'S:\::$SECURITY_DESCRIPTOR'
13:41:40       Looking for the first gap of at least 2 clusters after Lcn=0.
13:41:41         Gap found: Lcn=4867119, Size=380881
13:41:41       Moving 'S:\::$SECURITY_DESCRIPTOR' (Inode=5)
13:41:41         Could not open: [5] Access is denied.
13:41:41         Changing the item into 'not movable'.
13:41:41         Calculating the end of the zone.
13:41:41           ZoneBegin = 0
13:41:41           Number of clusters in selected items = 0
13:41:41           Iteration 1: 0 unmovable clusters between 0 and 0, ZoneEnd = 0
13:41:41           Re-using old ZoneEnd: 0
13:41:41       File is unmovable: 'S:\::$SECURITY_DESCRIPTOR'
13:41:41     Processing: 'S:\$Bitmap'
13:41:41       Looking for the first gap of at least 1000 clusters after Lcn=0.
13:41:41         Gap found: Lcn=4867119, Size=380881
13:41:41       Moving 'S:\$Bitmap' (Inode=6)
13:41:41         Could not open: [5] Access is denied.
13:41:41         Changing the item into 'not movable'.
13:41:41         Calculating the end of the zone.
13:41:41           ZoneBegin = 0
13:41:41           Number of clusters in selected items = 0
13:41:41           Iteration 1: 0 unmovable clusters between 0 and 0, ZoneEnd = 0
13:41:41           Re-using old ZoneEnd: 0
13:41:41       File is unmovable: 'S:\$Bitmap'
13:41:41     Processing: 'S:\$MFTMirr'
13:41:41       Looking for the first gap of at least 1 clusters after Lcn=0.
13:41:41         Gap found: Lcn=4867119, Size=380881
13:41:41       Moving 'S:\$MFTMirr' (Inode=1)
13:41:41         Moving 1 clusters to Lcn=4867119.
13:41:41         API is moving 1 clusters at offset=0 to Lcn=4867119.
13:41:41         The Windows defragmentation API has refused to move the item.
13:41:41         Getting fragment list for: S:\$MFTMirr
13:41:41           Extent: Lcn=41031014, Vcn=0, NextVcn=1
13:41:41           Translating into fragment tree....
13:41:41           Counting fragments....
13:41:41         Changing the item into 'not movable'.
13:41:41         Calculating the end of the zone.
13:41:41           ZoneBegin = 0
13:41:41           Number of clusters in selected items = 0
13:41:41           Iteration 1: 0 unmovable clusters between 0 and 0, ZoneEnd = 0
13:41:41           Re-using old ZoneEnd: 0
13:41:41       File is unmovable: 'S:\$MFTMirr'
13:41:41     Processing: 'S:\$LogFile'
13:41:41       Looking for the first gap of at least 1000 clusters after Lcn=0.
13:41:41         Gap found: Lcn=4867119, Size=380881
13:41:41       Moving 'S:\$LogFile' (Inode=2)
13:41:41         Could not open: [5] Access is denied.
13:41:41         Changing the item into 'not movable'.
13:41:41         Calculating the end of the zone.
13:41:41           ZoneBegin = 0
13:41:41           Number of clusters in selected items = 0
13:41:41           Iteration 1: 0 unmovable clusters between 0 and 0, ZoneEnd = 0
13:41:41           Re-using old ZoneEnd: 0
13:41:41       File is unmovable: 'S:\$LogFile'
13:41:41     Finished loading list of unmovable items.
13:41:41   Merging wrap-around fragments.
13:41:41     Looking at: S:\Games\The Lord of the Rings Online\client_highres.dat, 2 fragments
13:41:41       Wrap-around fragments found, now 1 fragments.
13:41:41     Found 1 items with wrap-around fragments.
13:41:41     Finished Scanning for items with wrap-around fragments.
13:41:41   Calculating the maximum end of the gap.
13:41:41     Number of clusters in remaining items: 57165527
13:41:41     Iteration 1: 16394 unmovable clusters after 24896501, new ZoneBegin = 24880107
13:41:41     Iteration 2: 16394 unmovable clusters after 24880107, new ZoneBegin = 24880107
13:41:41     Maximum end of gap = 24880107
13:41:41   Calculating the maximum end of the gap.
13:41:41     Number of clusters in remaining items: 57165527
13:41:41     Iteration 1: 16394 unmovable clusters after 24896501, new ZoneBegin = 24880107
13:41:41     Iteration 2: 16394 unmovable clusters after 24880107, new ZoneBegin = 24880107
13:41:41     Maximum end of gap = 24880107
13:41:42   Cleaning up old data from memory.
13:41:42     Finished cleaning up old data from memory.
13:41:42   The volume has already been analyzed, using existing data.
13:41:42   Vacating free area
13:41:42     Evaluating expression at line 12 column 19...
13:41:42     Calculating the maximum end of the gap.
13:41:42       Number of clusters in remaining items: 57165527
13:41:42       Iteration 1: 16394 unmovable clusters after 24896501, new ZoneBegin = 24880107
13:41:42       Iteration 2: 16394 unmovable clusters after 24880107, new ZoneBegin = 24880107
13:41:42       Maximum end of gap = 24880107
13:41:42     Value of macro !VolumeUsed! = 234227474432.000000
13:41:42       Number 1 = 2.342275e+011 (234227474432)
13:41:42       Number 2 = 3.000000e-001 (0)
13:41:42       Result = 7.026824e+010 (70268242329)
13:41:42     Evaluating expression at line 12 column 36...
13:41:42     Calculating the maximum end of the gap.
13:41:42       Number of clusters in remaining items: 57165527
13:41:42       Iteration 1: 16394 unmovable clusters after 24896501, new ZoneBegin = 24880107
13:41:42       Iteration 2: 16394 unmovable clusters after 24880107, new ZoneBegin = 24880107
13:41:42       Maximum end of gap = 24880107
13:41:42     Value of macro !VolumeSize! = 336126066688.000000
13:41:42       Number 1 = 3.361261e+011 (336126066688)
13:41:42       Number 2 = 2.000000e-002 (0)
13:41:42       Result = 6.722521e+009 (6722521333)
13:41:42     MakeGap has set the beginning of the next zone to LCN=18053646.

[ff_mfg]

Code:

13:41:42   Zone 1 of 6
13:41:42   Starting FileSelect for zone 1 (at line 15 column 3).
13:41:42     Cleaning up old data from memory.
13:41:42       Finished cleaning up old data from memory.
13:41:42     The volume has already been analyzed, using existing data.
13:41:42     Starting FileBoolean.
13:41:42     Executing NtfsSystemFiles(YES)
13:41:43     Finished FileBoolean.
13:41:43     Starting FileActions.
13:41:43     Calculating the end of the zone.
13:41:43       ZoneBegin = 18053646
13:41:43       Number of clusters in selected items = 72194
13:41:43       Iteration 1: 112 unmovable clusters between 18053646 and 18125840, ZoneEnd = 18125952
13:41:43       Iteration 2: 224 unmovable clusters between 18053646 and 18125952, ZoneEnd = 18126064
13:41:43       Iteration 3: 336 unmovable clusters between 18053646 and 18126064, ZoneEnd = 18126176
13:41:43       Iteration 4: 448 unmovable clusters between 18053646 and 18126176, ZoneEnd = 18126288
13:41:43       Iteration 5: 560 unmovable clusters between 18053646 and 18126288, ZoneEnd = 18126400
13:41:43       Iteration 6: 672 unmovable clusters between 18053646 and 18126400, ZoneEnd = 18126512
13:41:43       Iteration 7: 784 unmovable clusters between 18053646 and 18126512, ZoneEnd = 18126624
13:41:43       Iteration 8: 896 unmovable clusters between 18053646 and 18126624, ZoneEnd = 18126736
13:41:43       Iteration 9: 1008 unmovable clusters between 18053646 and 18126736, ZoneEnd = 18126848
13:41:43       Iteration 10: 1120 unmovable clusters between 18053646 and 18126848, ZoneEnd = 18126960
13:41:43       Iteration 11: 1232 unmovable clusters between 18053646 and 18126960, ZoneEnd = 18127072
13:41:43       Iteration 12: 1344 unmovable clusters between 18053646 and 18127072, ZoneEnd = 18127184
13:41:43       Iteration 13: 1456 unmovable clusters between 18053646 and 18127184, ZoneEnd = 18127296
13:41:43       Iteration 14: 1568 unmovable clusters between 18053646 and 18127296, ZoneEnd = 18127408
13:41:43       Iteration 15: 1680 unmovable clusters between 18053646 and 18127408, ZoneEnd = 18127520
13:41:43       Iteration 16: 1792 unmovable clusters between 18053646 and 18127520, ZoneEnd = 18127632
13:41:43       Iteration 17: 1904 unmovable clusters between 18053646 and 18127632, ZoneEnd = 18127744
13:41:43       Iteration 18: 2016 unmovable clusters between 18053646 and 18127744, ZoneEnd = 18127856
13:41:43       Iteration 19: 2128 unmovable clusters between 18053646 and 18127856, ZoneEnd = 18127968
13:41:43       Iteration 20: 2240 unmovable clusters between 18053646 and 18127968, ZoneEnd = 18128080
13:41:43       Iteration 21: 2352 unmovable clusters between 18053646 and 18128080, ZoneEnd = 18128192
13:41:43       Iteration 22: 2464 unmovable clusters between 18053646 and 18128192, ZoneEnd = 18128304
13:41:43       Iteration 23: 2576 unmovable clusters between 18053646 and 18128304, ZoneEnd = 18128416
13:41:43       Iteration 24: 2688 unmovable clusters between 18053646 and 18128416, ZoneEnd = 18128528
13:41:43       Iteration 25: 2800 unmovable clusters between 18053646 and 18128528, ZoneEnd = 18128640
13:41:43       Iteration 26: 2912 unmovable clusters between 18053646 and 18128640, ZoneEnd = 18128752
13:41:43       Iteration 27: 3024 unmovable clusters between 18053646 and 18128752, ZoneEnd = 18128864
13:41:43       Iteration 28: 3136 unmovable clusters between 18053646 and 18128864, ZoneEnd = 18128976
13:41:43       Iteration 29: 3248 unmovable clusters between 18053646 and 18128976, ZoneEnd = 18129088
13:41:43       Iteration 30: 3360 unmovable clusters between 18053646 and 18129088, ZoneEnd = 18129200
13:41:43       Iteration 31: 3472 unmovable clusters between 18053646 and 18129200, ZoneEnd = 18129312
13:41:43       Iteration 32: 3584 unmovable clusters between 18053646 and 18129312, ZoneEnd = 18129424
13:41:43       Iteration 33: 3696 unmovable clusters between 18053646 and 18129424, ZoneEnd = 18129536
13:41:43       Iteration 34: 3808 unmovable clusters between 18053646 and 18129536, ZoneEnd = 18129648
13:41:43       Iteration 35: 3920 unmovable clusters between 18053646 and 18129648, ZoneEnd = 18129760
13:41:43       Iteration 36: 4032 unmovable clusters between 18053646 and 18129760, ZoneEnd = 18129872
13:41:43       Iteration 37: 4144 unmovable clusters between 18053646 and 18129872, ZoneEnd = 18129984
13:41:43       Iteration 38: 4256 unmovable clusters between 18053646 and 18129984, ZoneEnd = 18130096
13:41:43       Iteration 39: 4368 unmovable clusters between 18053646 and 18130096, ZoneEnd = 18130208
13:41:43       Iteration 40: 4480 unmovable clusters between 18053646 and 18130208, ZoneEnd = 18130320
13:41:43       Iteration 41: 4592 unmovable clusters between 18053646 and 18130320, ZoneEnd = 18130432
13:41:43       Iteration 42: 4704 unmovable clusters between 18053646 and 18130432, ZoneEnd = 18130544
13:41:43       Iteration 43: 4816 unmovable clusters between 18053646 and 18130544, ZoneEnd = 18130656
13:41:43       Iteration 44: 4928 unmovable clusters between 18053646 and 18130656, ZoneEnd = 18130768
13:41:43       Iteration 45: 5040 unmovable clusters between 18053646 and 18130768, ZoneEnd = 18130880
13:41:43       Iteration 46: 5152 unmovable clusters between 18053646 and 18130880, ZoneEnd = 18130992
13:41:43       Iteration 47: 5264 unmovable clusters between 18053646 and 18130992, ZoneEnd = 18131104
13:41:43       Iteration 48: 5376 unmovable clusters between 18053646 and 18131104, ZoneEnd = 18131216
13:41:43       Iteration 49: 5488 unmovable clusters between 18053646 and 18131216, ZoneEnd = 18131328
13:41:43       Iteration 50: 5600 unmovable clusters between 18053646 and 18131328, ZoneEnd = 18131440
13:41:43       Iteration 51: 5712 unmovable clusters between 18053646 and 18131440, ZoneEnd = 18131552
13:41:43       Iteration 52: 5824 unmovable clusters between 18053646 and 18131552, ZoneEnd = 18131664
13:41:43       Iteration 53: 5936 unmovable clusters between 18053646 and 18131664, ZoneEnd = 18131776
13:41:43       Iteration 54: 6048 unmovable clusters between 18053646 and 18131776, ZoneEnd = 18131888
13:41:43       Iteration 55: 6160 unmovable clusters between 18053646 and 18131888, ZoneEnd = 18132000
13:41:43       Iteration 56: 6272 unmovable clusters between 18053646 and 18132000, ZoneEnd = 18132112
13:41:43       Iteration 57: 6384 unmovable clusters between 18053646 and 18132112, ZoneEnd = 18132224
13:41:43       Iteration 58: 6496 unmovable clusters between 18053646 and 18132224, ZoneEnd = 18132336
13:41:43       Iteration 59: 6608 unmovable clusters between 18053646 and 18132336, ZoneEnd = 18132448
13:41:43       Iteration 60: 6720 unmovable clusters between 18053646 and 18132448, ZoneEnd = 18132560
13:41:43       Iteration 61: 6832 unmovable clusters between 18053646 and 18132560, ZoneEnd = 18132672
13:41:43       Iteration 62: 6944 unmovable clusters between 18053646 and 18132672, ZoneEnd = 18132784
13:41:43       Iteration 63: 7056 unmovable clusters between 18053646 and 18132784, ZoneEnd = 18132896
13:41:43       Iteration 64: 7168 unmovable clusters between 18053646 and 18132896, ZoneEnd = 18133008
13:41:43       Iteration 65: 7232 unmovable clusters between 18053646 and 18133008, ZoneEnd = 18133072
13:41:43       Iteration 66: 7232 unmovable clusters between 18053646 and 18133072, ZoneEnd = 18133072
13:41:43       New ZoneEnd = 18133072
13:41:43     Evaluating expression at line 18 column 36...
13:41:43     Calculating the maximum end of the gap.
13:41:43       Number of clusters in remaining items: 57093333
13:41:43       Iteration 1: 16394 unmovable clusters after 24968695, new ZoneBegin = 24952301
13:41:43       Iteration 2: 16394 unmovable clusters after 24952301, new ZoneBegin = 24952301
13:41:43       Maximum end of gap = 24952301
13:41:43     Value of macro !MftSize! = 295256064.000000
13:41:43       Number 1 = 2.952561e+008 (295256064)
13:41:43       Number 2 = 1.000000e-001 (0)
13:41:43       Result = 2.952561e+007 (29525606)
13:41:43     Starting PlaceNtfsSystemFiles.
13:41:43     SortBy
13:41:43       Creating sorted list.
13:41:43         Finished creating sorted list.
13:41:43       Placing items in sorted order.
13:41:43         I want to place Inode=4 ('S:\$AttrDef') at Lcn=18053646, 1 clusters.
13:41:43           Testing if 'S:\$AttrDef' (Inode=4) is already at LCN=18053646
13:41:43             Yes, it is exactly there.
13:41:43         I want to place 'S:\$MFT' at Lcn=18053647, 72084 clusters.
13:41:43           Testing if 'S:\$MFT' is already at LCN=18053647
13:41:43             Yes, it is exactly there.
13:41:43         Creating space for the NTFS reserved area, 7208 clusters from LCN=18125731 to 18132939.
13:41:43         Vacating items from LCN=18125731 until there are at least 7208 free clusters.
13:41:43           I want to move 1 clusters at LCN=18132939 of item 'S:\$Secure:$SDH:$INDEX_ALLOCATION' (Inode=9).
13:41:43             Looking for the first gap of 1 clusters after Lcn=18133072, or the largest gap.
13:41:43               Gap found: Lcn=37265540, Size=1
13:41:43             Moving 'S:\$Secure:$SDH:$INDEX_ALLOCATION' (Inode=9)
13:41:43               Moving 1 clusters to Lcn=37265540.
13:41:43               API is moving 1 clusters at offset=0 to Lcn=37265540.
13:41:43               Getting fragment list for: S:\$Secure:$SDH:$INDEX_ALLOCATION
13:41:43                 Extent: Lcn=37265540, Vcn=0, NextVcn=1
13:41:43                 Translating into fragment tree....
13:41:43                 Counting fragments....
13:41:43               Checking block at Lcn=37265540, offset=0, size=1 clusters.
13:41:43                 Block was moved correctly.
13:41:43           There are now 0 free clusters, 7208 more to go.
13:41:43           I want to move 66 clusters at LCN=18132940 of item 'S:\$Secure:$SDS:$DATA' (Inode=9).
13:41:43             Looking for the first gap of 66 clusters after Lcn=18140148, or the largest gap.
13:41:44               Gap found: Lcn=37871349, Size=120
13:41:44             Moving 'S:\$Secure:$SDS:$DATA' (Inode=9)
13:41:44               Moving 66 clusters to Lcn=37871349.
13:41:44               API is moving 66 clusters at offset=0 to Lcn=37871349.
13:41:44               Getting fragment list for: S:\$Secure:$SDS:$DATA
13:41:44                 Extent: Lcn=37871349, Vcn=0, NextVcn=66
13:41:44                 Translating into fragment tree....
13:41:44                 Counting fragments....
13:41:44               Checking block at Lcn=37871349, offset=0, size=66 clusters.
13:41:44                 Block was moved correctly.
13:41:44           I want to move 1 clusters at LCN=18133006 of item 'S:\$Secure:$SII:$INDEX_ALLOCATION' (Inode=9).
13:41:44             Moving 'S:\$Secure:$SII:$INDEX_ALLOCATION' (Inode=9)
13:41:44               Moving 1 clusters to Lcn=37871415.
13:41:44               API is moving 1 clusters at offset=0 to Lcn=37871415.
13:41:44               Getting fragment list for: S:\$Secure:$SII:$INDEX_ALLOCATION
13:41:44                 Extent: Lcn=37871415, Vcn=0, NextVcn=1
13:41:44                 Translating into fragment tree....
13:41:44                 Counting fragments....
13:41:44               Checking block at Lcn=37871415, offset=0, size=1 clusters.
13:41:44                 Block was moved correctly.
13:41:44           I want to move 32 clusters at LCN=18133007 of item 'S:\$UpCase' (Inode=10).
13:41:44             Moving 'S:\$UpCase' (Inode=10)
13:41:44               Moving 32 clusters to Lcn=37871416.
13:41:44               API is moving 32 clusters at offset=0 to Lcn=37871416.
13:41:44               Getting fragment list for: S:\$UpCase
13:41:44                 Extent: Lcn=37871416, Vcn=0, NextVcn=32
13:41:44                 Translating into fragment tree....
13:41:44                 Counting fragments....
13:41:44               Checking block at Lcn=37871416, offset=0, size=32 clusters.
13:41:44                 Block was moved correctly.
13:41:44           I want to move 9 clusters at LCN=18133039 of item 'S:\$Extend\$ObjId:$O:$INDEX_ALLOCATION' (Inode=25).
13:41:44             Moving 'S:\$Extend\$ObjId:$O:$INDEX_ALLOCATION' (Inode=25)
13:41:44               Moving 9 clusters to Lcn=37871448.
13:41:44               API is moving 9 clusters at offset=0 to Lcn=37871448.
13:41:44               Getting fragment list for: S:\$Extend\$ObjId:$O:$INDEX_ALLOCATION
13:41:44                 Extent: Lcn=37871448, Vcn=0, NextVcn=9
13:41:44                 Translating into fragment tree....
13:41:44                 Counting fragments....
13:41:44               Checking block at Lcn=37871448, offset=0, size=9 clusters.
13:41:44                 Block was moved correctly.
13:41:44           I want to move 24 clusters at LCN=18133048 of item 'S:\E\GPP9\2HOME_560\photosight\nu\644420.jpg' (Inode=249072).
13:41:44             Looking for the first gap of 24 clusters after Lcn=18140148, or the largest gap.
13:41:44               Gap found: Lcn=37587172, Size=24
13:41:44             Moving 'S:\E\GPP9\2HOME_560\photosight\nu\644420.jpg' (Inode=249072)
13:41:44               Moving 24 clusters to Lcn=37587172.
13:41:44               API is moving 24 clusters at offset=0 to Lcn=37587172.
13:41:44               Getting fragment list for: S:\E\GPP9\2HOME_560\photosight\nu\644420.jpg
13:41:44                 Extent: Lcn=37587172, Vcn=0, NextVcn=24
13:41:44                 Translating into fragment tree....
13:41:44                 Counting fragments....
13:41:44               Checking block at Lcn=37587172, offset=0, size=24 clusters.
13:41:44                 Block was moved correctly.
13:41:44           I want to move 4 clusters at LCN=18133072 of item 'S:\' (Inode=5).
13:41:44             Looking for the first gap of 4 clusters after Lcn=18140148, or the largest gap.
13:41:45               Gap found: Lcn=37587115, Size=23
13:41:45             Moving 'S:\' (Inode=5)
13:41:45               Moving 4 clusters to Lcn=37587115.
13:41:45               API is moving 4 clusters at offset=0 to Lcn=37587115.
13:41:45               Getting fragment list for: S:\
13:41:45                 Extent: Lcn=37587115, Vcn=0, NextVcn=4
13:41:45                 Translating into fragment tree....
13:41:45                 Counting fragments....
13:41:45               Checking block at Lcn=37587115, offset=0, size=4 clusters.
13:41:45                 Block was moved correctly.
13:41:45           I want to move 1 clusters at LCN=18133076 of item 'S:\Backup' (Inode=287509).
13:41:45             Moving 'S:\Backup' (Inode=287509)
13:41:45               Moving 1 clusters to Lcn=37587119.
13:41:45               API is moving 1 clusters at offset=0 to Lcn=37587119.
13:41:45               Getting fragment list for: S:\Backup
13:41:45                 Extent: Lcn=37587119, Vcn=0, NextVcn=1
13:41:45                 Translating into fragment tree....
13:41:45                 Counting fragments....
13:41:45               Checking block at Lcn=37587119, offset=0, size=1 clusters.
13:41:45                 Block was moved correctly.

What I was talking about - it begins to free up space by moving directories away.
I'll skip the long list...

[ff_mfg]

Code:

13:42:08           I want to move 15 clusters at LCN=18140164 of item 'S:\E\Fraps_Screenshots\2SORT 2006-10--11' (Inode=9554).
13:42:08             Moving 'S:\E\Fraps_Screenshots\2SORT 2006-10--11' (Inode=9554)
13:42:08               Moving 15 clusters to Lcn=37918002.
13:42:08               API is moving 15 clusters at offset=0 to Lcn=37918002.
13:42:08               Getting fragment list for: S:\E\Fraps_Screenshots\2SORT 2006-10--11
13:42:08                 Extent: Lcn=37918002, Vcn=0, NextVcn=15
13:42:08                 Translating into fragment tree....
13:42:08                 Counting fragments....
13:42:08               Checking block at Lcn=37918002, offset=0, size=15 clusters.
13:42:08                 Block was moved correctly.
13:42:08           There are now 15 free clusters.
13:42:08         Looking for the first gap of at least 1 clusters after Lcn=18125731.
13:42:08           Gap found: Lcn=18125731, Size=14448
13:42:08         Space for the NTFS reserved area is now 7208 clusters from LCN=18125731 to 18132939.
13:42:08         Calculating the end of the zone.
13:42:08           ZoneBegin = 18053646
13:42:08           Number of clusters in selected items = 72194
13:42:08           Iteration 1: 112 unmovable clusters between 18053646 and 18125840, ZoneEnd = 18125952
13:42:08           Iteration 2: 224 unmovable clusters between 18053646 and 18125952, ZoneEnd = 18126064
13:42:08           Iteration 3: 336 unmovable clusters between 18053646 and 18126064, ZoneEnd = 18126176
13:42:08           Iteration 4: 448 unmovable clusters between 18053646 and 18126176, ZoneEnd = 18126288
13:42:08           Iteration 5: 560 unmovable clusters between 18053646 and 18126288, ZoneEnd = 18126400
13:42:08           Iteration 6: 672 unmovable clusters between 18053646 and 18126400, ZoneEnd = 18126512
13:42:08           Iteration 7: 784 unmovable clusters between 18053646 and 18126512, ZoneEnd = 18126624
13:42:08           Iteration 8: 896 unmovable clusters between 18053646 and 18126624, ZoneEnd = 18126736
13:42:08           Iteration 9: 1008 unmovable clusters between 18053646 and 18126736, ZoneEnd = 18126848
13:42:08           Iteration 10: 1120 unmovable clusters between 18053646 and 18126848, ZoneEnd = 18126960
13:42:08           Iteration 11: 1232 unmovable clusters between 18053646 and 18126960, ZoneEnd = 18127072
13:42:08           Iteration 12: 1344 unmovable clusters between 18053646 and 18127072, ZoneEnd = 18127184
13:42:08           Iteration 13: 1456 unmovable clusters between 18053646 and 18127184, ZoneEnd = 18127296
13:42:08           Iteration 14: 1568 unmovable clusters between 18053646 and 18127296, ZoneEnd = 18127408
13:42:08           Iteration 15: 1680 unmovable clusters between 18053646 and 18127408, ZoneEnd = 18127520
13:42:08           Iteration 16: 1792 unmovable clusters between 18053646 and 18127520, ZoneEnd = 18127632
13:42:08           Iteration 17: 1904 unmovable clusters between 18053646 and 18127632, ZoneEnd = 18127744
13:42:08           Iteration 18: 2016 unmovable clusters between 18053646 and 18127744, ZoneEnd = 18127856
13:42:08           Iteration 19: 2128 unmovable clusters between 18053646 and 18127856, ZoneEnd = 18127968
13:42:08           Iteration 20: 2240 unmovable clusters between 18053646 and 18127968, ZoneEnd = 18128080
13:42:08           Iteration 21: 2352 unmovable clusters between 18053646 and 18128080, ZoneEnd = 18128192
13:42:08           Iteration 22: 2464 unmovable clusters between 18053646 and 18128192, ZoneEnd = 18128304
13:42:08           Iteration 23: 2576 unmovable clusters between 18053646 and 18128304, ZoneEnd = 18128416
13:42:08           Iteration 24: 2688 unmovable clusters between 18053646 and 18128416, ZoneEnd = 18128528
13:42:08           Iteration 25: 2800 unmovable clusters between 18053646 and 18128528, ZoneEnd = 18128640
13:42:08           Iteration 26: 2912 unmovable clusters between 18053646 and 18128640, ZoneEnd = 18128752
13:42:08           Iteration 27: 3024 unmovable clusters between 18053646 and 18128752, ZoneEnd = 18128864
13:42:08           Iteration 28: 3136 unmovable clusters between 18053646 and 18128864, ZoneEnd = 18128976
13:42:08           Iteration 29: 3248 unmovable clusters between 18053646 and 18128976, ZoneEnd = 18129088
13:42:08           Iteration 30: 3360 unmovable clusters between 18053646 and 18129088, ZoneEnd = 18129200
13:42:08           Iteration 31: 3472 unmovable clusters between 18053646 and 18129200, ZoneEnd = 18129312
13:42:08           Iteration 32: 3584 unmovable clusters between 18053646 and 18129312, ZoneEnd = 18129424
13:42:08           Iteration 33: 3696 unmovable clusters between 18053646 and 18129424, ZoneEnd = 18129536
13:42:08           Iteration 34: 3808 unmovable clusters between 18053646 and 18129536, ZoneEnd = 18129648
13:42:08           Iteration 35: 3920 unmovable clusters between 18053646 and 18129648, ZoneEnd = 18129760
13:42:08           Iteration 36: 4032 unmovable clusters between 18053646 and 18129760, ZoneEnd = 18129872
13:42:08           Iteration 37: 4144 unmovable clusters between 18053646 and 18129872, ZoneEnd = 18129984
13:42:08           Iteration 38: 4256 unmovable clusters between 18053646 and 18129984, ZoneEnd = 18130096
13:42:08           Iteration 39: 4368 unmovable clusters between 18053646 and 18130096, ZoneEnd = 18130208
13:42:08           Iteration 40: 4480 unmovable clusters between 18053646 and 18130208, ZoneEnd = 18130320
13:42:08           Iteration 41: 4592 unmovable clusters between 18053646 and 18130320, ZoneEnd = 18130432
13:42:08           Iteration 42: 4704 unmovable clusters between 18053646 and 18130432, ZoneEnd = 18130544
13:42:08           Iteration 43: 4816 unmovable clusters between 18053646 and 18130544, ZoneEnd = 18130656
13:42:08           Iteration 44: 4928 unmovable clusters between 18053646 and 18130656, ZoneEnd = 18130768
13:42:08           Iteration 45: 5040 unmovable clusters between 18053646 and 18130768, ZoneEnd = 18130880
13:42:08           Iteration 46: 5152 unmovable clusters between 18053646 and 18130880, ZoneEnd = 18130992
13:42:08           Iteration 47: 5264 unmovable clusters between 18053646 and 18130992, ZoneEnd = 18131104
13:42:08           Iteration 48: 5376 unmovable clusters between 18053646 and 18131104, ZoneEnd = 18131216
13:42:08           Iteration 49: 5488 unmovable clusters between 18053646 and 18131216, ZoneEnd = 18131328
13:42:08           Iteration 50: 5600 unmovable clusters between 18053646 and 18131328, ZoneEnd = 18131440
13:42:08           Iteration 51: 5712 unmovable clusters between 18053646 and 18131440, ZoneEnd = 18131552
13:42:08           Iteration 52: 5824 unmovable clusters between 18053646 and 18131552, ZoneEnd = 18131664
13:42:08           Iteration 53: 5936 unmovable clusters between 18053646 and 18131664, ZoneEnd = 18131776
13:42:08           Iteration 54: 6048 unmovable clusters between 18053646 and 18131776, ZoneEnd = 18131888
13:42:08           Iteration 55: 6160 unmovable clusters between 18053646 and 18131888, ZoneEnd = 18132000
13:42:08           Iteration 56: 6272 unmovable clusters between 18053646 and 18132000, ZoneEnd = 18132112
13:42:08           Iteration 57: 6384 unmovable clusters between 18053646 and 18132112, ZoneEnd = 18132224
13:42:08           Iteration 58: 6496 unmovable clusters between 18053646 and 18132224, ZoneEnd = 18132336
13:42:08           Iteration 59: 6608 unmovable clusters between 18053646 and 18132336, ZoneEnd = 18132448
13:42:08           Iteration 60: 6720 unmovable clusters between 18053646 and 18132448, ZoneEnd = 18132560
13:42:08           Iteration 61: 6832 unmovable clusters between 18053646 and 18132560, ZoneEnd = 18132672
13:42:08           Iteration 62: 6944 unmovable clusters between 18053646 and 18132672, ZoneEnd = 18132784
13:42:08           Iteration 63: 7056 unmovable clusters between 18053646 and 18132784, ZoneEnd = 18132896
13:42:08           Iteration 64: 7168 unmovable clusters between 18053646 and 18132896, ZoneEnd = 18133008
13:42:08           Iteration 65: 7232 unmovable clusters between 18053646 and 18133008, ZoneEnd = 18133072
13:42:08           Iteration 66: 7232 unmovable clusters between 18053646 and 18133072, ZoneEnd = 18133072
13:42:08           Re-using old ZoneEnd: 18133072
13:42:08         I want to place Inode=9 ('S:\$Secure:$SDH:$INDEX_ALLOCATION') at Lcn=18132939, 1 clusters.
13:42:08           Testing if 'S:\$Secure:$SDH:$INDEX_ALLOCATION' (Inode=9) is already at LCN=18132939
13:42:08             No, it is at LCN=37265540.
13:42:08           Vacating items from LCN=18132939 until there are at least 1 free clusters.
13:42:08             No need to vacate, there are already 7219 free clusters at LCN=18132939.
13:42:08           Preemptive vacate of items not belonging to this zone, from LCN=18053646 to LCN=18056087.
13:42:08             Vacating movable items between LCN=18053646 and LCN=18056087.
13:42:08               Next movable item is at LCN=18140179, which is above LCN=18056087.
13:42:08               Finished vacating.
13:42:08           Looking for the first gap after Lcn=18132939.
13:42:08             Gap found: Lcn=18132939, Size=7240
13:42:08           Moving 'S:\$Secure:$SDH:$INDEX_ALLOCATION' (Inode=9)
13:42:08             Moving 1 clusters to Lcn=18132939.
13:42:08             API is moving 1 clusters at offset=0 to Lcn=18132939.
13:42:08             Getting fragment list for: S:\$Secure:$SDH:$INDEX_ALLOCATION
13:42:08               Extent: Lcn=18132939, Vcn=0, NextVcn=1
13:42:08               Translating into fragment tree....
13:42:08               Counting fragments....
13:42:08             Checking block at Lcn=18132939, offset=0, size=1 clusters.
13:42:08               Block was moved correctly.
13:42:08         I want to place Inode=9 ('S:\$Secure:$SDS:$DATA') at Lcn=18132940, 66 clusters.
13:42:08           No need to vacate, the gap at LCN=18132940 is large enough (7239 clusters).
13:42:08           Moving 'S:\$Secure:$SDS:$DATA' (Inode=9)
13:42:08             Moving 66 clusters to Lcn=18132940.
13:42:08             API is moving 66 clusters at offset=0 to Lcn=18132940.
13:42:08             Getting fragment list for: S:\$Secure:$SDS:$DATA
13:42:08               Extent: Lcn=18132940, Vcn=0, NextVcn=66
13:42:08               Translating into fragment tree....
13:42:08               Counting fragments....
13:42:08             Checking block at Lcn=18132940, offset=0, size=66 clusters.
13:42:08               Block was moved correctly.
13:42:08         I want to place Inode=9 ('S:\$Secure:$SII:$INDEX_ALLOCATION') at Lcn=18133006, 1 clusters.
13:42:08           No need to vacate, the gap at LCN=18133006 is large enough (7173 clusters).
13:42:08           Moving 'S:\$Secure:$SII:$INDEX_ALLOCATION' (Inode=9)
13:42:08             Moving 1 clusters to Lcn=18133006.
13:42:08             API is moving 1 clusters at offset=0 to Lcn=18133006.
13:42:08             Getting fragment list for: S:\$Secure:$SII:$INDEX_ALLOCATION
13:42:08               Extent: Lcn=18133006, Vcn=0, NextVcn=1
13:42:08               Translating into fragment tree....
13:42:08               Counting fragments....
13:42:08             Checking block at Lcn=18133006, offset=0, size=1 clusters.
13:42:08               Block was moved correctly.
13:42:08         I want to place Inode=10 ('S:\$UpCase') at Lcn=18133007, 32 clusters.
13:42:08           No need to vacate, the gap at LCN=18133007 is large enough (7172 clusters).
13:42:08           Moving 'S:\$UpCase' (Inode=10)
13:42:08             Moving 32 clusters to Lcn=18133007.
13:42:08             API is moving 32 clusters at offset=0 to Lcn=18133007.
13:42:08             Getting fragment list for: S:\$UpCase
13:42:08               Extent: Lcn=18133007, Vcn=0, NextVcn=32
13:42:08               Translating into fragment tree....
13:42:08               Counting fragments....
13:42:08             Checking block at Lcn=18133007, offset=0, size=32 clusters.
13:42:08               Block was moved correctly.
13:42:08         I want to place Inode=25 ('S:\$Extend\$ObjId:$O:$INDEX_ALLOCATION') at Lcn=18133039, 9 clusters.
13:42:08           No need to vacate, the gap at LCN=18133039 is large enough (7140 clusters).
13:42:08           Moving 'S:\$Extend\$ObjId:$O:$INDEX_ALLOCATION' (Inode=25)
13:42:08             Moving 9 clusters to Lcn=18133039.
13:42:08             API is moving 9 clusters at offset=0 to Lcn=18133039.
13:42:08             Getting fragment list for: S:\$Extend\$ObjId:$O:$INDEX_ALLOCATION
13:42:08               Extent: Lcn=18133039, Vcn=0, NextVcn=9
13:42:08               Translating into fragment tree....
13:42:08               Counting fragments....
13:42:08             Checking block at Lcn=18133039, offset=0, size=9 clusters.
13:42:08               Block was moved correctly.
13:42:08       Finished PlaceNtfsSystemFiles.
13:42:08     ZoneBegin is now 18133072.
13:42:09     Updating list of unmovable files at: C:\Program Files\MyDefrag\MyDefrag.dat
13:42:09       Finished updating list of unmovable items.
13:42:09     Merging wrap-around fragments.
13:42:09       Found 0 items with wrap-around fragments.
13:42:09       Finished Scanning for items with wrap-around fragments.
13:42:09     Finished FileActions.
13:42:09   Zone 2 of 6

It then proceeds to return the directories back, it's not so interesing.

Well, I don't see the failed attempts to move something in here that I guessed (except for those 'unmovable clusters' lists, I'm not sure what they are), but maybe you'll understand the log better. Anyway, the moving out and back in is defenitely happening, and it shouldn't.

[jeroen]

Thanks for the logfile, I appreciate it. I will take a look when I have time.

[WindHydra]

For the directories kept getting moved, you can try adding ExcludeFiles(FileName("$LogFile")) to your script.  It might be because $LogFile is unmovable (says so in the FAQ) but SelectNTFSSystemFiles selects it anyways and vacates space for it, only to find it unmovable and moves other stuff into the vacated space.  In the next run, MyDefrag will vacated for $LogFile again, thus the directory juggling.

[ff_mfg]

It's not the $LogFile. $LogFile is present on all volumes (after all, it's essential part of NTFS), and described behavior is observed only on some. Also, $LogFile, $Bitmap, $MFTMirr, etc. are present in mydefrag.dat - they are tested and known to be unmovable in the beginning. My guess was that it's because of some rare $ filesystem files. After reading in the log I'm not so sure, but still it might be...

[WHRoeder]

nd now I think I understand why the described is happening. The volumes where the problem appear have a number of unmovable NTFS system files. For example this one I'm mostly testing on has a bunch of filename::$ATTRIBUTE_LIST entries. I've looked them up, they are leftovers from a bunch of big hugely fragmented files, NTFS uses those $ATTRIBUTE_LIST when fragment lists are deemed to big for MFT itself. Those files are defragmented now, and I don't really understand why these are left hanging or why they are unmovable (btw, they are not listed in unmovables list or mydefrag.dat, but they are red on the map; there might be more such unlisted unmovables).

I've seen this also. The file has been defragged, but the $ATTRIBUTE_LIST remains and is unmovable.
If you copy the file, delete the original and rename the list is gone.

[jeroen]

And now I think I understand why the described is happening.

I have found the problem and it will be fixed in the next release. The problem was in the subroutine that vacates the NTFS reserved area, it vacated more than actually needed. The reserved area is normally counted as occupied disk space, but in this special case it must be counted as free space.