What is it doing?

Discussion in 'Paragon Partition Manager Product Line' started by brocks, Feb 4, 2010.

Thread Status:
Not open for further replies.
  1. brocks

    brocks Registered Member

    Joined:
    Jan 12, 2010
    Posts:
    39
    I've tried this with both PM10Free, and the PM built into BR10Compact.

    If I delete, create, and format partitions, it does it all in a couple of seconds. Works great.

    But if I tell it to mark a partition active, it takes about 30 seconds. Much longer than the other three operations combined.

    Why does it take so long? All that's done to mark a partition active is flip one bit in the MBR. I can actually start a sector editor from scratch and set the bit manually in less time than it takes PM to do it from the time I hit the "Apply" button. It does MUCH more work, in much less time, with the other operations I mentioned above. And it's not verifying that the files are bootable or anything, because it cheerfully marks a partition active, even if I change the partition identifier to say it's an Amoeba OS partition.

    So what is it doing for 30 seconds?
     
  2. Paragon_MattK

    Paragon_MattK Paragon Moderator

    Joined:
    Jan 14, 2010
    Posts:
    176
    Location:
    Irvine, CA
    I'm not sure why it is taking so long on your system, I was able to perform this operation nearly instantly on a VM with limited resources. What I recommend is installing ProcMon from Sysinternals, start the capture just before hitting "Apply" and exclude everything except launcher.exe. Then look for anything that says "FAILED" as a result, this should help diagnose the issue.

    http://technet.microsoft.com/en-us/sysinternals/bb896645.aspx
     
  3. brocks

    brocks Registered Member

    Joined:
    Jan 12, 2010
    Posts:
    39
    Thanks for your response. I already had Procmon on my system, but I didn't think to use it because I didn't think I had a problem --- but now that you tell me it only takes a second on your system, I guess I do. So I did as you suggested.

    Before I get to that, I should tell you what I am running, because it's kind of an unusual setup. My PC is running Win7-64 on a Gigabyte EP45-UD3R motherboard, 8GB memory, Intel C2D-E8500@3.16GHz, 3 internal drives, and two semi-internal drives. The semi-internal drives are connected to internal SATA cables that come out through a hole in the side of the case. The BIOS allows me to set them as hot swappable. Their power comes from a second PSU sitting on the table with a jumper to make it think it's plugged into a PC, so I can turn it on and off independent of the PC, and swap around the drives that are connected to it. Two of the internal drives are 2TB each, the other three drives are 1.5TB each, and each of them have four partitions. To further complicate things, three of the four partitions on each drive are encrypted with TrueCrypt, so when they are mounted it's like there are three more partitions on each drive. So add it all up, and PM might think it sees over 30 partitions.

    OK. I did exactly as you said, had the ProcMon capture off and cleared, the filter set to include only launcher.exe, and I started it just before I hit the apply button on PM, and stopped it as soon as the operation completed (which was simply to set one of the active partitions inactive). My CPU, drive, and net activity was very low - nothing but passive programs running.

    It took about 30 seconds, and Procmon captured 2568 events from launcher.exe.

    First line of the capture, just for the time stamp:
    10:09:59.0691411 PM launcher.exe RegQueryKey HKCU SUCCESS Query: HandleTags, HandleTags: 0x0 0

    The last "0" is the sequence number. The sequence numbers are handy to see where the lines end, because the formatting here is very confusing.

    I think these next few lines, sequence #196-204, are where I hit the "Apply" button. They contain the first ReadFile commands, and the first Buffer Overflow errors:

    10:09:59.2054544 PM launcher.exe ReadFile C:\Windows\SysWOW64\QTP-MT334.DLL SUCCESS Offset: 1,822,720, Length: 20,480, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O, Priority: Normal 196

    10:09:59.2340271 PM launcher.exe ReadFile C:\Windows\SysWOW64\QTP-MT334.DLL SUCCESS Offset: 1,855,488, Length: 4,096, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O, Priority: Normal 197

    10:09:59.2440531 PM launcher.exe ReadFile C:\PROGRAM FILES (X86)\PARAGON SOFTWARE\PARTITION MANAGER 2010 FREE EDITION\program\BASELIB100.DLL SUCCESS Offset: 2,326,528, Length: 32,768, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O, Priority: Normal 198

    10:09:59.2448577 PM launcher.exe RegQueryKey HKLM SUCCESS Query: HandleTags, HandleTags: 0x0 199

    10:09:59.2448875 PM launcher.exe RegOpenKey HKLM\SYSTEM\CurrentControlSet\Control\MiniNT REPARSE Desired Access: Maximum Allowed 200

    10:09:59.2449153 PM launcher.exe RegOpenKey HKLM\System\CurrentControlSet\Control\MiniNT NAME NOT FOUND Desired Access: Maximum Allowed 201

    10:09:59.2464773 PM launcher.exe CreateFile C:\Program Files (x86)\Paragon Software\Partition Manager 2010 Free Edition\program\resource\ui\progressdlgform.ui SUCCESS Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened 202

    10:09:59.2607878 PM launcher.exe QueryInformationVolume C:\Program Files (x86)\Paragon Software\Partition Manager 2010 Free Edition\program\resource\ui\progressdlgform.ui BUFFER OVERFLOW VolumeCreationTime: 12/5/2009 5:04:49 AM, VolumeSerialNumber: CC8C-4D01, SupportsObjects: True, VolumeLabel: s15Ð 203

    10:09:59.2608085 PM launcher.exe QueryAllInformationFile C:\Program Files (x86)\Paragon Software\Partition Manager 2010 Free Edition\program\resource\ui\progressdlgform.ui BUFFER OVERFLOW CreationTime: 11/18/2009 2:43:12 PM, LastAccessTime: 12/26/2009 7:29:35 PM, LastWriteTime: 11/18/2009 2:43:12 PM, ChangeTime: 12/26/2009 7:29:35 PM, FileAttributes: A, AllocationSize: 36,864, EndOfFile: 35,450, NumberOfLinks: 1, DeletePending: False, Directory: False, IndexNumber: 0x100000002187b, EaSize: 0, Access: Generic Read, Position: 0, Mode: Synchronous IO Non-Alert, AlignmentRequirement: Word 204

    From there to seq 358, there were mostly successful ReadFile and WriteFile commands. After that, I got an almost solid mass of BufferOverflow errors, e.g.:

    10:09:59.4392721 PM launcher.exe QueryInformationVolume C:\Program Files (x86)\Paragon Software\Partition Manager 2010 Free Edition\program\resource\img\generic_progress.mng BUFFER OVERFLOW VolumeCreationTime: 12/5/2009 5:04:49 AM, VolumeSerialNumber: CC8C-4D01, SupportsObjects: True, VolumeLabel: s15Ð 359

    10:09:59.4393022 PM launcher.exe QueryAllInformationFile C:\Program Files (x86)\Paragon Software\Partition Manager 2010 Free Edition\program\resource\img\generic_progress.mng BUFFER OVERFLOW CreationTime: 11/18/2009 2:43:08 PM, LastAccessTime: 12/26/2009 7:29:34 PM, LastWriteTime: 11/18/2009 2:43:08 PM, ChangeTime: 12/26/2009 7:29:34 PM, FileAttributes: A, AllocationSize: 360,448, EndOfFile: 360,027, NumberOfLinks: 1, DeletePending: False, Directory: False, IndexNumber: 0x1000000021549, EaSize: 0, Access: Generic Read, Position: 4,096, Mode: Synchronous IO Non-Alert, AlignmentRequirement: Word 360

    10:09:59.4575067 PM launcher.exe QueryInformationVolume C:\Program Files (x86)\Paragon Software\Partition Manager 2010 Free Edition\program\resource\img\generic_progress.mng BUFFER OVERFLOW VolumeCreationTime: 12/5/2009 5:04:49 AM, VolumeSerialNumber: CC8C-4D01, SupportsObjects: True, VolumeLabel: s15Ð 361

    10:09:59.4575319 PM launcher.exe QueryAllInformationFile C:\Program Files (x86)\Paragon Software\Partition Manager 2010 Free Edition\program\resource\img\generic_progress.mng BUFFER OVERFLOW CreationTime: 11/18/2009 2:43:08 PM, LastAccessTime: 12/26/2009 7:29:34 PM, LastWriteTime: 11/18/2009 2:43:08 PM, ChangeTime: 12/26/2009 7:29:34 PM, FileAttributes: A, AllocationSize: 360,448, EndOfFile: 360,027, NumberOfLinks: 1, DeletePending: False, Directory: False, IndexNumber: 0x1000000021549, EaSize: 0, Access: Generic Read, Position: 4,096, Mode: Synchronous IO Non-Alert, AlignmentRequirement: Word 362

    10:09:59.4700074 PM launcher.exe QueryInformationVolume C:\Program Files (x86)\Paragon Software\Partition Manager 2010 Free Edition\program\resource\img\generic_progress.mng BUFFER OVERFLOW VolumeCreationTime: 12/5/2009 5:04:49 AM, VolumeSerialNumber: CC8C-4D01, SupportsObjects: True, VolumeLabel: s15Ð 363

    10:09:59.4700333 PM launcher.exe QueryAllInformationFile C:\Program Files (x86)\Paragon Software\Partition Manager 2010 Free Edition\program\resource\img\generic_progress.mng BUFFER OVERFLOW CreationTime: 11/18/2009 2:43:08 PM, LastAccessTime: 12/26/2009 7:29:34 PM, LastWriteTime: 11/18/2009 2:43:08 PM, ChangeTime: 12/26/2009 7:29:34 PM, FileAttributes: A, AllocationSize: 360,448, EndOfFile: 360,027, NumberOfLinks: 1, DeletePending: False, Directory: False, IndexNumber: 0x1000000021549, EaSize: 0, Access: Generic Read, Position: 4,096, Mode: Synchronous IO Non-Alert, AlignmentRequirement: Word 364

    10:09:59.4900029 PM launcher.exe QueryInformationVolume C:\Program Files (x86)\Paragon Software\Partition Manager 2010 Free Edition\program\resource\img\generic_progress.mng BUFFER OVERFLOW VolumeCreationTime: 12/5/2009 5:04:49 AM, VolumeSerialNumber: CC8C-4D01, SupportsObjects: True, VolumeLabel: s15Ð 365

    10:09:59.4900274 PM launcher.exe QueryAllInformationFile C:\Program Files (x86)\Paragon Software\Partition Manager 2010 Free Edition\program\resource\img\generic_progress.mng BUFFER OVERFLOW CreationTime: 11/18/2009 2:43:08 PM, LastAccessTime: 12/26/2009 7:29:34 PM, LastWriteTime: 11/18/2009 2:43:08 PM, ChangeTime: 12/26/2009 7:29:34 PM, FileAttributes: A, AllocationSize: 360,448, EndOfFile: 360,027, NumberOfLinks: 1, DeletePending: False, Directory: False, IndexNumber: 0x1000000021549, EaSize: 0, Access: Generic Read, Position: 4,096, Mode: Synchronous IO Non-Alert, AlignmentRequirement: Word 366

    From here on, there were about ten BufferOverflow errors for every success. Here are the last few lines of that stretch:

    10:10:08.1750170 PM launcher.exe QueryAllInformationFile C:\Program Files (x86)\Paragon Software\Partition Manager 2010 Free Edition\program\resource\img\generic_progress.mng BUFFER OVERFLOW CreationTime: 11/18/2009 2:43:08 PM, LastAccessTime: 12/26/2009 7:29:34 PM, LastWriteTime: 11/18/2009 2:43:08 PM, ChangeTime: 12/26/2009 7:29:34 PM, FileAttributes: A, AllocationSize: 360,448, EndOfFile: 360,027, NumberOfLinks: 1, DeletePending: False, Directory: False, IndexNumber: 0x1000000021549, EaSize: 0, Access: Generic Read, Position: 360,027, Mode: Synchronous IO Non-Alert, AlignmentRequirement: Word 1252

    10:10:08.1750461 PM launcher.exe QueryInformationVolume C:\Program Files (x86)\Paragon Software\Partition Manager 2010 Free Edition\program\resource\img\generic_progress.mng BUFFER OVERFLOW VolumeCreationTime: 12/5/2009 5:04:49 AM, VolumeSerialNumber: CC8C-4D01, SupportsObjects: True, VolumeLabel: s15Ð 1253

    10:10:08.1750677 PM launcher.exe QueryAllInformationFile C:\Program Files (x86)\Paragon Software\Partition Manager 2010 Free Edition\program\resource\img\generic_progress.mng BUFFER OVERFLOW CreationTime: 11/18/2009 2:43:08 PM, LastAccessTime: 12/26/2009 7:29:34 PM, LastWriteTime: 11/18/2009 2:43:08 PM, ChangeTime: 12/26/2009 7:29:34 PM, FileAttributes: A, AllocationSize: 360,448, EndOfFile: 360,027, NumberOfLinks: 1, DeletePending: False, Directory: False, IndexNumber: 0x1000000021549, EaSize: 0, Access: Generic Read, Position: 360,027, Mode: Synchronous IO Non-Alert, AlignmentRequirement: Word 1254

    10:10:08.3478124 PM launcher.exe CreateFile C:\Program Files (x86)\Paragon Software\Partition Manager 2010 Free Edition\program\BioNtLog.txt SUCCESS Desired Access: Generic Write, Read Attributes, Disposition: OpenIf, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: 0, OpenResult: Opened 1255


    So it took about 9 seconds to get almost a thousand lines of Buffer overflows. But then there were 20 more seconds of almost pure successes, with maybe 10% "Fast I/O Disallowed" or "Name not Found" results, but during that 20 seconds, there were only about five operations per second. Here are a couple second's worth to show you the pattern:

    10:10:20.3481720 PM launcher.exe CloseFile C:\PROGRAM FILES (X86)\PARAGON SOFTWARE\PARTITION MANAGER 2010 FREE EDITION\program\BioNtLog.txt SUCCESS 1319

    10:10:21.3515593 PM launcher.exe CreateFile C:\Program Files (x86)\Paragon Software\Partition Manager 2010 Free Edition\program\BioNtLog.txt SUCCESS Desired Access: Generic Write, Read Attributes, Disposition: OpenIf, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: 0, OpenResult: Opened 1320

    10:10:21.3518135 PM launcher.exe QueryStandardInformationFile C:\PROGRAM FILES (X86)\PARAGON SOFTWARE\PARTITION MANAGER 2010 FREE EDITION\program\BioNtLog.txt SUCCESS AllocationSize: 24,576, EndOfFile: 22,422, NumberOfLinks: 1, DeletePending: False, Directory: False 1321

    10:10:21.3518300 PM launcher.exe QueryStandardInformationFile C:\PROGRAM FILES (X86)\PARAGON SOFTWARE\PARTITION MANAGER 2010 FREE EDITION\program\BioNtLog.txt SUCCESS AllocationSize: 24,576, EndOfFile: 22,422, NumberOfLinks: 1, DeletePending: False, Directory: False 1322

    10:10:21.3518452 PM launcher.exe WriteFile C:\PROGRAM FILES (X86)\PARAGON SOFTWARE\PARTITION MANAGER 2010 FREE EDITION\program\BioNtLog.txt SUCCESS Offset: 22,422, Length: 15, Priority: Normal 1323

    10:10:21.3518937 PM launcher.exe CloseFile C:\PROGRAM FILES (X86)\PARAGON SOFTWARE\PARTITION MANAGER 2010 FREE EDITION\program\BioNtLog.txt SUCCESS 1324

    10:10:22.3515224 PM launcher.exe CreateFile C:\Program Files (x86)\Paragon Software\Partition Manager 2010 Free Edition\program\BioNtLog.txt SUCCESS Desired Access: Generic Write, Read Attributes, Disposition: OpenIf, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: 0, OpenResult: Opened 1325

    10:10:22.3517850 PM launcher.exe QueryStandardInformationFile C:\PROGRAM FILES (X86)\PARAGON SOFTWARE\PARTITION MANAGER 2010 FREE EDITION\program\BioNtLog.txt SUCCESS AllocationSize: 24,576, EndOfFile: 22,437, NumberOfLinks: 1, DeletePending: False, Directory: False 1326

    10:10:22.3518015 PM launcher.exe QueryStandardInformationFile C:\PROGRAM FILES (X86)\PARAGON SOFTWARE\PARTITION MANAGER 2010 FREE EDITION\program\BioNtLog.txt SUCCESS AllocationSize: 24,576, EndOfFile: 22,437, NumberOfLinks: 1, DeletePending: False, Directory: False 1327

    10:10:22.3518164 PM launcher.exe WriteFile C:\PROGRAM FILES (X86)\PARAGON SOFTWARE\PARTITION MANAGER 2010 FREE EDITION\program\BioNtLog.txt SUCCESS Offset: 22,437, Length: 15, Priority: Normal 1328

    10:10:22.3518759 PM launcher.exe CloseFile C:\PROGRAM FILES (X86)\PARAGON SOFTWARE\PARTITION MANAGER 2010 FREE EDITION\program\BioNtLog.txt SUCCESS 1329

    10:10:23.3515648 PM launcher.exe CreateFile C:\Program Files (x86)\Paragon Software\Partition Manager 2010 Free Edition\program\BioNtLog.txt SUCCESS Desired Access: Generic Write, Read Attributes, Disposition: OpenIf, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: 0, OpenResult: Opened 1330

    The five ops per second timing ended at about seq 1360, although the same pattern of operations kept up till seq 1412.

    This is the next line after that, the first one that breaks the pattern:

    10:10:29.3556597 PM launcher.exe ReadFile \Device\Harddisk0\DR0 SUCCESS Offset: 0, Length: 512, I/O Flags: Non-cached, Priority: Normal 1413

    It went through a bunch of those, a bunch of WriteFiles in a row, a bunch of ReadFiles in a row, and a bunch of Reg Queries. Somewhere in the last second, it finished, and I stopped the capture. It did over 1200 ops in the last second, compared to about 100 in the previous 20 seconds.

    Don't know if any of that helps you. This is VERY repeatable, so if you want more detail, or if you want me to set different columns to record, I can easily do it. But it may just be that the number of partitions and the encrypted partitions are confusing it. As I noted in another thread, both Paragon products and Windows Disk Management sometimes take over a minute to show the drive map when I have encrypted partitions mounted, although they both take much less time when I don't, and yet the 30 seconds for flipping the active bit seems to be constant. And as I said, PM does create, delete, and format operations in just a couple of seconds.

    Thanks again for the response.
     
    Last edited: Feb 5, 2010
Thread Status:
Not open for further replies.