Windows Vista Beta | WinVistaBeta.com - Message | Excessive (loggin ??? IO)

July 05, 2008  
Subject: Excessive (loggin ??? IO)
Group: microsoft.public.winternals
Date: 1/23/2008 6:25:14 PM
From: "Villy Madsen" [Email Address Protection]

For a long time - since about the XP SP2 rollout, I have been plagued with
strange disk IO taking place. It is noticeable only files that I have
created to use as virtual disks for my vax emulation.

When the files are created on a NTFS partition, this excessive IO resolves
to a large number of 4KB (this could be the cluster size) reads from the
file (virtual disk) and an equal number of 64KB writes to the $logfile.

the # of bytes written appear to equal the size of the file in question. I
have reduced the impact somewhat by increasing the NTFS logfile to 250mb,
but it still happens - albeit somewhat more sporatically than before.
Pre-extending the file to it's maximum may have been part of the
mitigation - but again it didn't stop it.

I then moved the files to a FAT32 partition , and now I get the following:

I should add that I found at least one similar complaint googling, but it
related to someone using MYSQL, again - large files. Currently the problem
is happening with files that are 1.47 GB in size...

18:04:49 Filemon.exe:1756 IRP_MJ_QUERY_VOLUME_INFORMATION I:\ SUCCESS
FileFsAttributeInformation
18:04:49 Filemon.exe:1756 IRP_MJ_CLEANUP I:\ SUCCESS
18:04:49 Filemon.exe:1756 IRP_MJ_CLOSE I:\ SUCCESS
18:04:49 Filemon.exe:1756 IRP_MJ_QUERY_VOLUME_INFORMATION J:\ SUCCESS
FileFsAttributeInformation
18:04:49 Filemon.exe:1756 IRP_MJ_CLEANUP J:\ SUCCESS
18:04:49 Filemon.exe:1756 IRP_MJ_CLOSE J:\ SUCCESS
18:04:49 Filemon.exe:1756 IRP_MJ_QUERY_VOLUME_INFORMATION K:\ SUCCESS
FileFsAttributeInformation
18:04:49 Filemon.exe:1756 IRP_MJ_CLEANUP K:\ SUCCESS
18:04:49 Filemon.exe:1756 IRP_MJ_CLOSE K:\ SUCCESS
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1304887296 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1304952832 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305018368 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305083904 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305149440 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305214976 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305280512 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305346048 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305411584 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305477120 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305542656 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305608192 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305673728 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305739264 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305804800 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305870336 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305935872 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1306001408 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1306066944 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1306132480 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1306198016 Length:
65536
18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1306263552 Length:
65536
bunch deleted

18:05:00 vax.exe:2404 IRP_MJ_WRITE* I: SUCCESS Offset: 0 Length: 4096
18:05:00 svchost.exe:124 IRP_MJ_CREATE I:\System Volume
Information\_restore{7B1A29F3-C4A4-4248-B792-18ECFA6F3340}\RP611\RestorePointSize
SUCCESS Options: OverwriteIf Access: 00120196
18:05:00 svchost.exe:124 IRP_MJ_CREATE I:\System Volume
Information\_restore{7B1A29F3-C4A4-4248-B792-18ECFA6F3340}\RP611\ SUCCESS
Options: Open Directory Access: 00100000
18:05:00 svchost.exe:124 IRP_MJ_WRITE I:\System Volume
Information\_restore{7B1A29F3-C4A4-4248-B792-18ECFA6F3340}\RP611\RestorePointSize
SUCCESS Offset: 0 Length: 8
18:05:00 svchost.exe:124 IRP_MJ_CLEANUP I:\System Volume
Information\_restore{7B1A29F3-C4A4-4248-B792-18ECFA6F3340}\RP611\RestorePointSize
SUCCESS
18:05:00 svchost.exe:124 IRP_MJ_CREATE I:\System Volume
Information\_restore{7B1A29F3-C4A4-4248-B792-18ECFA6F3340}\RP611\RestorePointSize
SUCCESS Options: OverwriteIf Access: 00120196
18:05:00 svchost.exe:124 IRP_MJ_CREATE I:\System Volume
Information\_restore{7B1A29F3-C4A4-4248-B792-18ECFA6F3340}\RP611\ SUCCESS
Options: Open Directory Access: 00100000
18:05:00 svchost.exe:124 IRP_MJ_WRITE I:\System Volume
Information\_restore{7B1A29F3-C4A4-4248-B792-18ECFA6F3340}\RP611\RestorePointSize
SUCCESS Offset: 0 Length: 8
18:05:00 svchost.exe:124 IRP_MJ_CLEANUP I:\System Volume
Information\_restore{7B1A29F3-C4A4-4248-B792-18ECFA6F3340}\RP611\RestorePointSize
SUCCESS
18:05:00 svchost.exe:124 IRP_MJ_CLOSE I:\System Volume
Information\_restore{7B1A29F3-C4A4-4248-B792-18ECFA6F3340}\RP611\RestorePointSize
SUCCESS
and a bunch more deleted.

Villy Madsen CISA ISP

(and old time vax fanatic)



Back
Subject: Re: Excessive (loggin ??? IO)
Group: microsoft.public.winternals
Date: 1/25/2008 6:59:22 AM
From: "villy" [Email Address Protection]

Just discovered that the fix is to turn off system restore on the partition
(drive). I've been chasing this for almost 2 years - it never occurred to
me that restore points worked at the drive level...

Villy



"Villy Madsen" <Villy.Madsen@shaw.ca> wrote in message
news:O7ik3fiXIHA.3940@TK2MSFTNGP05.phx.gbl...
> For a long time - since about the XP SP2 rollout, I have been plagued with
> strange disk IO taking place. It is noticeable only files that I have
> created to use as virtual disks for my vax emulation.
>
> When the files are created on a NTFS partition, this excessive IO resolves
> to a large number of 4KB (this could be the cluster size) reads from the
> file (virtual disk) and an equal number of 64KB writes to the $logfile.
>
> the # of bytes written appear to equal the size of the file in question.
> I have reduced the impact somewhat by increasing the NTFS logfile to
> 250mb, but it still happens - albeit somewhat more sporatically than
> before. Pre-extending the file to it's maximum may have been part of the
> mitigation - but again it didn't stop it.
>
> I then moved the files to a FAT32 partition , and now I get the following:
>
> I should add that I found at least one similar complaint googling, but it
> related to someone using MYSQL, again - large files. Currently the
> problem is happening with files that are 1.47 GB in size...
>
> 18:04:49 Filemon.exe:1756 IRP_MJ_QUERY_VOLUME_INFORMATION I:\ SUCCESS
> FileFsAttributeInformation
> 18:04:49 Filemon.exe:1756 IRP_MJ_CLEANUP I:\ SUCCESS
> 18:04:49 Filemon.exe:1756 IRP_MJ_CLOSE I:\ SUCCESS
> 18:04:49 Filemon.exe:1756 IRP_MJ_QUERY_VOLUME_INFORMATION J:\ SUCCESS
> FileFsAttributeInformation
> 18:04:49 Filemon.exe:1756 IRP_MJ_CLEANUP J:\ SUCCESS
> 18:04:49 Filemon.exe:1756 IRP_MJ_CLOSE J:\ SUCCESS
> 18:04:49 Filemon.exe:1756 IRP_MJ_QUERY_VOLUME_INFORMATION K:\ SUCCESS
> FileFsAttributeInformation
> 18:04:49 Filemon.exe:1756 IRP_MJ_CLEANUP K:\ SUCCESS
> 18:04:49 Filemon.exe:1756 IRP_MJ_CLOSE K:\ SUCCESS
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1304887296 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1304952832 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305018368 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305083904 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305149440 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305214976 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305280512 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305346048 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305411584 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305477120 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305542656 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305608192 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305673728 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305739264 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305804800 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305870336 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1305935872 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1306001408 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1306066944 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1306132480 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1306198016 Length:
> 65536
> 18:04:49 vax.exe:2404 IRP_MJ_READ* I: SUCCESS Offset: 1306263552 Length:
> 65536
> bunch deleted
>
> 18:05:00 vax.exe:2404 IRP_MJ_WRITE* I: SUCCESS Offset: 0 Length: 4096
> 18:05:00 svchost.exe:124 IRP_MJ_CREATE I:\System Volume
> Information\_restore{7B1A29F3-C4A4-4248-B792-18ECFA6F3340}\RP611\RestorePointSize
> SUCCESS Options: OverwriteIf Access: 00120196
> 18:05:00 svchost.exe:124 IRP_MJ_CREATE I:\System Volume
> Information\_restore{7B1A29F3-C4A4-4248-B792-18ECFA6F3340}\RP611\ SUCCESS
> Options: Open Directory Access: 00100000
> 18:05:00 svchost.exe:124 IRP_MJ_WRITE I:\System Volume
> Information\_restore{7B1A29F3-C4A4-4248-B792-18ECFA6F3340}\RP611\RestorePointSize
> SUCCESS Offset: 0 Length: 8
> 18:05:00 svchost.exe:124 IRP_MJ_CLEANUP I:\System Volume
> Information\_restore{7B1A29F3-C4A4-4248-B792-18ECFA6F3340}\RP611\RestorePointSize
> SUCCESS
> 18:05:00 svchost.exe:124 IRP_MJ_CREATE I:\System Volume
> Information\_restore{7B1A29F3-C4A4-4248-B792-18ECFA6F3340}\RP611\RestorePointSize
> SUCCESS Options: OverwriteIf Access: 00120196
> 18:05:00 svchost.exe:124 IRP_MJ_CREATE I:\System Volume
> Information\_restore{7B1A29F3-C4A4-4248-B792-18ECFA6F3340}\RP611\ SUCCESS
> Options: Open Directory Access: 00100000
> 18:05:00 svchost.exe:124 IRP_MJ_WRITE I:\System Volume
> Information\_restore{7B1A29F3-C4A4-4248-B792-18ECFA6F3340}\RP611\RestorePointSize
> SUCCESS Offset: 0 Length: 8
> 18:05:00 svchost.exe:124 IRP_MJ_CLEANUP I:\System Volume
> Information\_restore{7B1A29F3-C4A4-4248-B792-18ECFA6F3340}\RP611\RestorePointSize
> SUCCESS
> 18:05:00 svchost.exe:124 IRP_MJ_CLOSE I:\System Volume
> Information\_restore{7B1A29F3-C4A4-4248-B792-18ECFA6F3340}\RP611\RestorePointSize
> SUCCESS
> and a bunch more deleted.
>
> Villy Madsen CISA ISP
>
> (and old time vax fanatic)
>



Back