Инструментарий управления Windows (WMI) — технология, широко используемая на сервере и клиенте Windows для решения различных задач, в частности для проведения инвентаризации оборудования и программ, определения работающих служб и процессов. Обычно WMI работает без затруднений, но, если таковые возникают, диагностика может оказаться сложной. Например, одна из распространенных проблем WMI — высокая пиковая загрузка процессора при выполнении одного из процессов провайдера (wmiprvse.exe). Процесс провайдера относится к выполнению запросов WMI, а процесс службы WMI (svchost.exe) — к возвращению результатов выполнения запроса WMI создавшему его процессу. Любому администратору, вероятно, приходилось сталкиваться с высокой загрузкой процессора при работе WMI либо с необходимостью просмотра поступающих запросов WMI. Анализируя проблемы загрузки процессора, полезно просматривать выполняемые запросы и определять, откуда они поступили.

К сожалению, в лучшем случае просмотр поступающих запросов WMI — трудоемкий процесс, способный свести на нет попытки администратора установить, какие же запросы WMI выполняются в данной системе. Ниже предлагается способ просмотра поступающих запросов в режиме, максимально приближенном к реальному времени, с определением их источника. Этот способ позволяет быстро проводить диагностику распространенных проблем высокой загрузки процессора без необходимости выполнения сложных шагов отладки, сканирования сотен событий, регистрируемых в журналах, или обращения в группу технической поддержки.

Извлечение журналов трассировки WMI

Как описано в статье «Ведение журнала отладки WMI» (tinyurl.com/3a6b7ls), для просмотра журналов трассировки WMI можно включить механизм трассировки в окне Event Viewer. Однако ввиду большого числа регистрируемых событий сложно выделить недавние запросы и определить время их выполнения и источник поступления. Механизм фильтрации, встроенный в меню Event Viewer, не позволяет выводить на экран только запросы WMI.

Запустите из командной стройки программу wevtutil.exe. Эта программа, включенная в Windows Vista и более новые версии, позволяет извлекать информацию из журналов событий, осуществлять экспорт данных, выполнять запросы и задавать параметры для журналов. В частности, с помощью Wevtutil можно устанавливать признак трассировки для журнала событий WMI в локальном и удаленном режиме, обеспечивая вывод данных трассировки в окно Event Viewer.

Ниже приведен синтаксис установки признака трассировки для файла журнала WMIActivity (из окна командной строки с повышенными привилегиями) и сообщение, отображаемое после ввода команды:

C:\Windows\system32>wevtutil sl Microsoft-
   Windows-WMIActivity/Trace/e: true

**** Warning: Enabling this type of log clears
   it. Do you want to enable and
clear this log? [y/n]:
y

Ответное сообщение содержит предупреждение об очистке журнала при включении трассировки (для выключения признака трассировки очистка журнала не требуется). Имеется также параметр /r, позволяющий устанавливать признак трассировки на удаленной системе.

После установки признака трассировки начинается вывод «информационных» событий журнала WMI-Activity. Однако эти данные выводятся с большой степенью детализации, а имеющийся механизм фильтрации не позволяет организовать вывод одних только запросов WMI. Вновь воспользуемся программой wevtutil.exe для просмотра поступающих запросов WMI вручную.

Ниже приведен синтаксис команды просмотра запросов WMI с использованием программы Wevtutil (запускаемой после включения признака трассировки из окна командной строки с повышенными привилегиями).

c:\>wevtutil qe Microsoft-Windows-WMI-
   Activity/Trace/q:"*[System[(Level=4
   or Level=0) and (EventID=1)]]"
   |findstr/i execquery

Параметр qe означает «события запросов из файла журнала»; затем вводится имя файла журнала (Microsoft-Windows-WMIActivity/Trace). Параметр /q: предписывает отфильтровать данные из журнала, оставляя только конкретные события; в этом случае мы запрашиваем «Level 4 or Level 0 AND Event ID=1», указывая идентификатор события, под которым регистрируются все запросы WMI. Затем к результатам применяем функцию поиска строк (findstr) и выполняем фильтрацию, оставляя только команды execquery.

Пример результата выполнения команды показан на экране 1. Этот результат выдается только для одного запроса — нетрудно представить объем информации для сотни таких запросов! Это огромное количество данных, требующих анализа. Однако можно сменить формат выходных данных с XML на текстовый, внеся небольшое изменение в команду Wevtutil:

C:\>wevtutil qe Microsoft-Windows-WMI-
   Activity/Trace/q:"*[System[(Level=4
   or Level=0) and (EventID=1)]]"
   /f: text |findstr/i execquery

Внесенное изменение заключается лишь в добавлении параметра /f: (формат) и указании текстового формата.

Теперь выходной результат, показанный на экране 2, более удобен для восприятия, но все же слишком громоздок для быстрого просмотра поступающих запросов WMI; кроме того, отсутствуют отметки времени поступления запроса.

Автоматизация трассировки событий WMI

Было бы удобно иметь сценарий, выполнение которого можно было задать через расписание и который бы обеспечивал выдачу удобных для восприятия данных с отметкой времени возникновения событий и позволял просматривать самые «свежие» запросы с момента последнего выполнения сценария. Именно эту задачу выполнила группа поддержки Microsoft. Был создан сценарий выдачи поступающих запросов WMI с указанием времени их поступления. В зависимости от используемой версии Windows можно установить, какая система и какой процесс являются инициаторами запроса, в локальном или удаленном режиме. Сценарий WMIActivity.vbs запрашивает события WMI и выводит информацию только о деятельности, связанной с событиями (см. листинг).

На экране 3 показан выходной результат в формате Excel. Имеется несколько столбцов данных, несущих информацию о времени выполнения запроса, о самом запросе, о системе, с которой он поступил (столбец ClientMachine), и о клиентском процессе, инициировавшем запрос (столбец Client Process ID).

Заметим, что в столбцах ClientMachine и ClientProcessID присутствуют данные, характерные только для систем Windows 7 и Windows Server 2008 R2 или более новых версий. В Vista и Windows Server 2008 не включен код регистрации клиента, инициировавшего запрос, или идентификатора клиентского процесса.

При первом выполнении сценария отметка времени помещается непосредственно в реестр в раздел HKLM\Software\WinITPro. При каждом выполнении сценария эта отметка времени проверяется, и извлекаются только более «свежие» записи. Таким образом, выдаются лишь самые новые запросы, что избавляет от необходимости просматривать одну и ту же информацию или проходить через громоздкое меню в стиле Event Viewer.

Преобразуем столбец TimeCreated в привычный формат. Для этого выделим столбец, а затем в окне, открываемом щелчком правой клавишей, выберем «форматирование ячейки», как показано на экране 4. Можно также создать сводную таблицу, анализируя запросы с точки зрения статистики.

Экран 4. Форматирование столбца TimeCreated

Дополнительная помощь в диагностике

Сценарий WMIActivity.vbs позволяет просматривать поступающие в систему запросы WMI в режиме, максимально приближенном к реальному времени. Это облегчает диагностику проблем высокой загрузки процессора, связанной с деятельностью WMI, а также дает более четкое представление об источниках запросов.

Шон Уилер (seanw@microsoft.com) — старший инженер в команде Microsoft Premier Support, поддерживающей корпоративных клиентов. Один из создателей инструмента MPS Reporting, специалист по написанию сценариев и отладке

Экран 1. Выходные данные Wevtutil

Экран 2. Выходные данные Wevtutil в текстовом формате

Экран 3. Выходные данные сценария WMIActivity.vbs

Листинг. Сценарий WMIActivity.vbs 
‘’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’
' WMIActivity.vbs - seanw@microsoft.com
' This script uses wevtutil.exe to query for WMI Activity events and outputs only those events
' that show the WMI query being requested.
''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''
option explicit
on error resume next
Const ForReading    = 1, ForWriting = 2, ForAppending = 8

dim fso  : set fso  = createobject("scripting.filesystemobject")
dim wshShell  : set wshShell  = createobject("wscript.shell")
Dim strRegLogPath  : strRegLogPath  = "HKLM\SOFTWARE\WinITPro\"
Dim strAppName  : strAppName  = "WMIActivity"
Dim outputStream  : set outputStream  = wscript.stdout

Dim xmlWMIActivityDoc  : set xmlWMIActivityDoc  = createobject("Msxml2.DOMDocument.3.0")
Dim objWMIActivity  : set objWMIActivity  = new WMIActivityClass

Dim oExec, LastQueryTime
Dim querycmd, xmldata

LastQueryTime = wshShell.RegRead(strRegLogPath & strAppName & "\TimeStamp")
if err.number <> 0 then
   if err.number = &H80070002 then
      LastQueryTime = ""
      err.clear
   else 
      outputStream.writeline "Error  : 0x" & myhex(err.number,8)
      outputStream.writeline "Source  : " & err.Source
      outputStream.writeline "Description  : " & err.Description
      wscript.quit err.number
   end if
end if

if LastQueryTime = "" then
   querycmd = "wevtutil.exe qe Microsoft-Windows-WMI-Activity/Trace /f:xml /q:" & chr(34) & _
              "*[System[(Level=4 or Level=0) and (EventID=1)]]" & chr(34) & " /e:Events"
else
   querycmd = "wevtutil.exe qe Microsoft-Windows-Diagnostics-Performance/Operational /f:xml /q:" & chr(34) & _
              "*[System[(Level=4 or Level=0) and (EventID=1) and (TimeCreated[@SystemTime >
 '" & LastQueryTime & "'])]]" & chr(34) & " /e:Events"
end if

set oExec = wshShell.Exec(querycmd)
xmldata = oExec.StdOut.ReadAll
xmlWMIActivityDoc.loadxml(xmldata)
set oExec = nothing

dim rootNode,Node,operation

set rootNode = xmlWMIActivityDoc.selectSingleNode("//Events")
outputStream.writeline objWMIActivity.GetCSVHeader
for each Node in rootNode.childnodes
   operation = Node.selectSingleNode("UserData/Operation_/Operation").text
   if instr(lcase(operation),"execquery") <> 0 then
      with objWMIActivity
         .Computer  = Node.selectSingleNode("System/Computer").text
         LastQueryTime  = Node.selectSingleNode("System/TimeCreated").getAttribute("SystemTime")
         .TimeCreated  = fmtDateTime(LastQueryTime,0) ' second parameter
 is timezone bias (eg. -480 for Pacific Time)
         .Query  = mid(replace(operation,chr(34),chr(34) & chr(34)),33)
         .ClientMachine  = Node.selectSingleNode("UserData/Operation_/ClientMachine").text
         .User  = Node.selectSingleNode("UserData/Operation_/User").text
         .ClientProcessId  = Node.selectSingleNode("UserData/Operation_/ClientProcessId").text
         .Namespace  = Node.selectSingleNode("UserData/Operation_/NamespaceName").text
      end with
      outputStream.writeline objWMIActivity.GetCSVData
      objWMIActivity.Class_Initialize
   end if
next
wshShell.RegWrite strRegLogPath & strAppName & "\TimeStamp", LastQueryTime, "REG_SZ"
''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''
function fmtDateTime(byval strDateTime, byval tzBias)
   dim strDT, strMS, temp
   strDT = replace(left(strDateTime,19),"T"," ")
   strMS = mid(strDateTime,20,4)
   temp = cdate(strDT)+timeserial(0,tzBias,0)
   fmtDateTime = FormatDateTime(temp,2) & " " & right("0" & Hour(FormatDateTime(temp,3)),2) & ":" & _
                 right("0" & Minute(FormatDateTime(temp,3)),2) & ":" & right("0" & Second(FormatDate
                 Time(temp,3)),2) & strMS
end function

''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''
' Function  : MyHex(byval num, byval pad)
' Description  : pad hex
''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''
Function MyHex(byval num, byval pad)
    MyHex = right(string(pad,&H30) & hex(num),pad)
end function

''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''
' Class Definitions
''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''''
class WMIActivityClass
   private colHeader
   public Computer
   public TimeCreated
   public Query
   public ClientMachine
   public User
   public ClientProcessId
   public Namespace
   
   ''''''''''''''''''''''''''''''''
   public sub Class_Initialize
      colHeader = array("Computer","TimeCreated","Query","ClientMachine","User","ClientProcessId",
      "Namespace")
      Computer  = ""
      TimeCreated  = ""
      Query  = ""
      ClientMachine  = ""
      User  = ""
      ClientProcessId  = ""
      Namespace  = ""
   end sub
   ''''''''''''''''''''''''''''''''
   public function GetCSVHeader
      dim colSep : colSep = chr(34) & "," & chr(34)
      GetCSVHeader = chr(34) & join(colHeader,colSep) & chr(34)
   end function
   ''''''''''''''''''''''''''''''''
   public function GetCSVData
      dim arrData 
      dim colSep : colSep = chr(34) & "," & chr(34)
      arrData = array(Computer,TimeCreated,Query,ClientMachine,User,ClientProcessId,Namespace)
      GetCSVData = chr(34) & join(arrData,colSep) & chr(34)
   end function
end class
‘’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’’