Freitag, 25. Dezember 2009

Using PowerShell to log Start and Stop of Processes and watch some counters

Merry Christmas everyone.

Today I show a little of PowerShell script, which logs when processes start and when they end.

I wrote it, because I have a very unique problem with my Windows 7. Every now and then (that may be between 10 minutes and 4 hours, my system becomes unresponsive for about 60 seconds, while the the hard drive does some mystic thing.
After a lot of logging with PowerShell I came to the conclusion, that there is a definite correspondance between the length of the Current Disk Queue Length and my problem. Especially when Disk Transfers/sec stays at 0.

The current script helps me to determine the exact time when the problem occurs.
But I didn't yet find any corresponding entries in the event-log nor could I determine the process causing this issue.

           

$psold = get-Process

(
'\PhysicalDisk(_total)\Current Disk Queue Length',
'\PhysicalDisk(_total)\Disk Transfers/sec'
) | Get-Counter -cont -sample 1 |% {
$timestamp = "{0:T}" -f $_.Timestamp

$diskQueue = ($_.CounterSamples[0]).CookedValue
$transfer = ($_.CounterSamples[1]).CookedValue

$msg = "{0} {1,4:f0} {2,4:f0}" -f $timestamp, $diskQueue, $transfer

$psnew = get-Process

# Show Processes that started or stopped
Compare-Object $psold $psnew |%{
$ipo = $_.inputObject
$Name = $ipo.ProcessName
$Id = $ipo.Id
if ($_.Sideindicator -eq '=>')
{
"$timestamp Start $Id $Name"
}
if ($_.Sideindicator -eq '<=')
{
"$timestamp Stop $Id $Name"
}
}
$psold = $psnew

# the following code is special to a problem on my Windows 7 installation
# my problem is, when Current Disk Queue Length > 0, but Disk Transfers/sec 0
if ($diskQueue -gt 0 -and $transfer -eq 0)
{
$msg
}
}
A typical output on my system looks like this

PS C:\Var\bin> C:\Var\bin\topics\Perfmon\disk2.ps1
11:49:28 Start 7840 MultipleFirefoxLoader
11:49:30 Start 7036 firefox
11:49:30 Stop 7840 MultipleFirefoxLoader
11:50:16 Stop 6176 SearchFilterHost
11:50:16 Stop 3664 SearchProtocolHost
11:50:31 Stop 7036 firefox
11:50:44 Stop 1936 WmiPrvSE
11:51:23 1 0
11:52:44 1 0
11:54:44 1 0
11:54:47 1 0
11:54:48 1 0
11:54:49 1 0
11:54:51 4 0
11:54:52 4 0
11:54:53 9 0
11:54:54 9 0
11:54:55 10 0
11:54:56 10 0
11:54:57 10 0
11:54:59 10 0
11:55:00 11 0
11:55:01 11 0
11:55:02 11 0
11:55:03 11 0
11:55:04 11 0
11:55:05 11 0
11:55:06 11 0
11:55:08 11 0
11:55:09 11 0
11:55:10 11 0
11:55:11 12 0
11:55:12 15 0
11:55:13 Start 3252 audiodg
11:55:13 16 0
11:55:14 17 0
11:55:16 17 0
11:55:17 17 0
11:55:18 17 0
11:55:19 18 0
11:55:20 Start 5028 svchost
11:55:20 19 0
11:55:21 19 0
11:55:23 19 0
11:55:24 20 0
11:55:25 20 0
11:55:26 20 0
11:55:27 20 0
11:55:28 20 0
11:55:29 20 0
11:55:31 20 0
11:55:32 20 0
11:55:33 21 0
11:55:34 21 0
11:55:35 21 0
11:55:36 21 0
11:55:37 22 0
11:55:38 22 0
11:55:40 22 0
11:55:41 22 0
11:56:12 Stop 7712 chrome
11:56:28 Start 7712 chrome


In Resource Monitor that looks like this:

Keine Kommentare:

Kommentar veröffentlichen