4.2.5 hangs in endless CPU loop

[dheijl]

First run of 4.2.5 after uninstall of 4.2.4.

Screen contents:

Bezig met disk C: Zone 3 van 5 Snel vullen: 100 : Verplaatsten van 4096 bytes naar LCN = 929.511
C:\Windows\System32\icmp.dll

No disk activity, only CPU.

Process monitor shows Mydefrag looping on the following system call:

40886   16:25:39,8303021   MyDefrag.exe   2640   FileSystemControl   C:   BUFFER OVERFLOW   Control: FSCTL_GET_VOLUME_BITMAP

this message is repeated endlessly.

80 GB laptop disk, 28 GB free, loads of small files (several versions of Visual Studio, MSDN, etc).

Log contents:

# See the 'MyDefrag.log' file for information intended for endusers. This is the debug
# logfile. The contents is highly technical and not documented. See the 'Debug' setting
# or the '-d' commandline option to control the level of information in this file.
#
Version: MyDefrag v4.2.5
Date: 2009/11/04 15:45:48
Windows version: v5.1 build 2600 S
Commandline: "C:\Program Files\MyDefrag v4.2\MyDefrag.exe"
Working Directory: C:\Program Files\MyDefrag v4.2
Userid: dh
InstallPath = C:\Program Files\MyDefrag v4.2\
15:45:48 Analyzing the commandline.
15:45:48 Running script: Settings.MyD
15:45:48 Showing the WhatToDo dialog.
15:46:00 Added 'C:' to the list of CommandlineVolumes.
15:46:00 Selected script = C:\Program Files\MyDefrag v4.2\Scripts\OptimizeWeekly.MyD
15:46:00 Running script: C:\Program Files\MyDefrag v4.2\Scripts\OptimizeWeekly.MyD
15:46:00 Bezig met disk C:
15:46:49   Inlezen lijst van onverplaatsbare bestanden
15:46:49     Could not open handle for 'C:\Program Files\MyDefrag v4.2\MyDefrag.dat': [2] Het systeem kan het opgegeven bestand niet vinden.
15:46:50   Opschonen van het NTFS gereserveerd gebied
15:46:50   Gebied vrijmaken
15:46:50   Zone 1 van 5
15:46:51     Rangschikken
15:49:57       Could not open handle for 'C:\Program Files\MyDefrag v4.2\MyDefrag.dat': [2] Het systeem kan het opgegeven bestand niet vinden.
15:49:57   Zone 2 van 5
15:49:57     Rangschikken
15:49:58     Rangschikken
16:04:00   Zone 2 van 5
16:04:00   Gebied vrijmaken
16:04:00   Zone 3 van 5
16:04:00     Analyseren van het boot optimalizatie bestand
16:04:04       1338 files selected.
16:04:04     Defragmenteren
16:15:16     Snel vullen
16:33:07 Klaar met disk C:
16:33:07 Stopped.

[jeroen]

Thanks for posting your logfile, I appreciate it. Very strange, I need more information. Could you please make a debug logfile with more detail? For instructions see the I have a problem! page.

[dheijl]

Thanks for posting your logfile, I appreciate it. Very strange, I need more information. Could you please make a debug logfile with more detail? For instructions see the I have a problem! page.

it's too large to attach with Debug(175), the .7z size = 1248 KB (48 MB uncompressed).

An excerpt:


10:42:43           Moving 'C:\Documents and Settings\dh\Local Settings\Application Data\Mozilla\Firefox\Profiles\7f1gvlsi.default\Cache\32DF9402d01' (Inode=645)
10:42:43             Moving 2 clusters at offset=12 to Lcn=767982.
10:42:43             Getting fragment list for: C:\Documents and Settings\dh\Local Settings\Application Data\Mozilla\Firefox\Profiles\7f1gvlsi.default\Cache\32DF9402d01
10:42:43               Extent: Lcn=926229, Vcn=0, NextVcn=4
10:42:43               Extent: Lcn=917890, Vcn=4, NextVcn=12
10:42:43               Extent: Lcn=767982, Vcn=12, NextVcn=14
10:42:43               Counting clusters
10:42:43               FragmentArrayToTree
10:42:43               Counting fragments
10:42:43         I want to move 1 clusters at LCN=667194 of item 'C:\Documents and Settings\dh\Local Settings\Temp\A9RFFD3.tmp\Overview Software Release Guide.pdf' (Inode=322989).
10:42:43           Moving 'C:\Documents and Settings\dh\Local Settings\Temp\A9RFFD3.tmp\Overview Software Release Guide.pdf' (Inode=322989)
10:42:43             Could not open: [3] Het systeem kan het opgegeven pad niet vinden.
10:42:43             Changing the item into 'not movable'.
10:42:43             Calculating the end of the zone.
10:42:43               ZoneBegin = 0
10:42:43               Number of clusters in selected items = 754392
10:42:43               Iteration 1: 11580 unmovable clusters between 0 and 754392, ZoneEnd = 765972
10:42:43               Iteration 2: 11580 unmovable clusters between 0 and 765972, ZoneEnd = 765972
10:42:43               Re-using old ZoneEnd: 767656
10:42:43         Next movable item is at LCN=767656, which is above LCN=767656.
10:42:43         Finished vacating.
10:42:43       Starting to fill the gap at LCN=631327, size=136329 clusters.
10:42:43         There are 1 movable items above the gap, smallest is 221700 clusters, largest is 221700 clusters.
10:42:43         Trying to move away the item above the gap.
10:42:43           The end of the gap is above the end of the zone.
10:42:43         Cannot fill the gap, all items above the gap are bigger.
10:42:43       Starting to fill the gap at LCN=767984, size=560 clusters.
10:42:44         There are 1 movable items above the gap, smallest is 221700 clusters, largest is 221700 clusters.
10:42:44         Trying to move away the item above the gap.
10:42:44           The end of the gap is above the end of the zone.
10:42:44         Cannot fill the gap, all items above the gap are bigger.
10:42:44       Starting to fill the gap at LCN=892229, size=1 clusters.
10:42:44         There are 1 movable items above the gap, smallest is 221700 clusters, largest is 221700 clusters.
10:42:44         Trying to move away the item above the gap.
10:42:44           The end of the gap is above the end of the zone.
10:42:44         Cannot fill the gap, all items above the gap are bigger.
10:42:44       Starting to fill the gap at LCN=893063, size=1 clusters.
10:42:44         There are 1 movable items above the gap, smallest is 221700 clusters, largest is 221700 clusters.
10:42:44         Trying to move away the item above the gap.
10:42:44           The end of the gap is above the end of the zone.
10:42:44         Cannot fill the gap, all items above the gap are bigger.
10:42:44       Starting to fill the gap at LCN=896041, size=1 clusters.
10:42:44         There are 1 movable items above the gap, smallest is 221700 clusters, largest is 221700 clusters.
10:42:44         Trying to move away the item above the gap.
10:42:44           The end of the gap is above the end of the zone.
10:42:44         Cannot fill the gap, all items above the gap are bigger.
10:42:44       Starting to fill the gap at LCN=896055, size=1 clusters.
10:42:44         There are 1 movable items above the gap, smallest is 221700 clusters, largest is 221700 clusters.
10:42:44         Trying to move away the item above the gap.
10:42:44           The end of the gap is above the end of the zone.
10:42:44         Cannot fill the gap, all items above the gap are bigger.
10:42:44       Starting to fill the gap at LCN=899381, size=1 clusters.
10:42:44         There are 1 movable items above the gap, smallest is 221700 clusters, largest is 221700 clusters.
10:42:44         Trying to move away the item above the gap.
10:42:44           The end of the gap is above the end of the zone.
10:42:44         Cannot fill the gap, all items above the gap are bigger.
10:42:44       Starting to fill the gap at LCN=909749, size=1 clusters.
10:42:44         There are 1 movable items above the gap, smallest is 221700 clusters, largest is 221700 clusters.
10:42:44         Trying to move away the item above the gap.
10:42:44           The end of the gap is above the end of the zone.
10:42:44         Cannot fill the gap, all items above the gap are bigger.
10:42:44       Starting to fill the gap at LCN=913202, size=1 clusters.
10:42:44         There are 1 movable items above the gap, smallest is 221700 clusters, largest is 221700 clusters.
10:42:44         Trying to move away the item above the gap.
10:42:44           The end of the gap is above the end of the zone.
10:42:44         Cannot fill the gap, all items above the gap are bigger.

... endlessly repeated ... until I stopped MyDefrag

10:43:43       Starting to fill the gap at LCN=3897496, size=14 clusters.
10:43:43         There are 1 movable items above the gap, smallest is 221700 clusters, largest is 221700 clusters.
10:43:43         Trying to move away the item above the gap.
10:43:43           The end of the gap is above the end of the zone.
10:43:43         Cannot fill the gap, all items above the gap are bigger.
10:43:43       Starting to fill the gap at LCN=3897511, size=1 clusters.
10:43:43         Saved 'Software\MyDefrag\WindowPosition' = '0 842 0 500 0 1 -1 -1 -32000 -32000 1680 1050'
10:43:43         Stopping....
10:43:43         There are 1 movable items above the gap, smallest is 221700 clusters, largest is 221700 clusters.
10:43:43         Trying to move away the item above the gap.
10:43:43           The end of the gap is above the end of the zone.
10:43:43         Cannot fill the gap, all items above the gap are bigger.
10:43:43     Read key 'SOFTWARE\Microsoft\Windows\CurrentVersion\Uninstall\MyDefrag v4.2.5_is1\InstallLocation' from registry: 'C:\Program Files\MyDefrag v4.2\'
10:43:43     Updating list of unmovable files at: C:\Program Files\MyDefrag v4.2\MyDefrag.dat
10:43:43       Loading file into memory: C:\Program Files\MyDefrag v4.2\MyDefrag.dat
10:43:43       Finished updating list of unmovable items.
10:43:43     Merging wrap-around fragments.
10:43:44       Found 0 items with wrap-around fragments.
10:43:44       Finished Scanning for items with wrap-around fragments.
10:43:44     Finished FileActions.
10:43:44   Finished VolumeActions.
10:43:44 Finished VolumeSelect.
10:43:44 Klaar met disk C:
10:43:44 Finished executing the script.
10:43:44 Resetting ScreenSaverTimeout to 300
10:43:44 Resetting PowerOffTimeout to 900
10:43:44 Stopped.

[jeroen]

According to your logfile the program was not looping, it was walking through a lot of small gaps trying to fill them. In other words, this is not a bug. Let the program continue and eventually it will finish. If you are unhappy about how long it takes then consider using the Daily script instead of the Weekly script.

[dheijl]

OK thanks for clarifying that.

The first time I let it run at 100 % cpu and no progress for close to an hour, so I thought it must be an endless loop.

[dheijl]

According to your logfile the program was not looping, it was walking through a lot of small gaps trying to fill them. In other words, this is not a bug. Let the program continue and eventually it will finish. If you are unhappy about how long it takes then consider using the Daily script instead of the Weekly script.

I could not reproduce this with 4.2.6, now Mydefrag finishes without a hitch (constantly moving stuff around without "stalling" in 100 % CPU).

I did not try to defragment again with another script than the 4.2.5 weekly before trying 4.2.6.

[jeroen]

Thanks for the feedback, I appreciate it. I am glad to hear that the program is working fine for you now.