January 9, 2010
In the earlier post, you saw a script output that looked something like the following:
1/8/2010 12:57:56 PM Processes: 73 Threads: 861 C. Switches: 35972 Q. Length: 6 Instance: c:\oracle\product\10.2.0\db_1\bin\ORACLE.EXE OR10 User Time: 9.33S Sys Time: 25.19S Memory: 141.11MB Page File: 0.63MB Handle: 1444 User Time: 9.34S Sys Time: 25.5S ElapsedTime: 70S Priority: 8 ThreadState: In Run Queue Instance: c:\oracle\product\11.1.0\db_1\bin\ORACLE.EXE OR11 User Time: 103.9S Sys Time: 0.13S Memory: 442.42MB Page File: 0.67MB Handle: 3520 User Time: 34.13S Sys Time: 0.02S ElapsedTime: 69S Priority: 8 ThreadState: Running PID:18 SPID:3520 SID:146 SERIAL#:4 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe DECLARE i NUMBER := 0; STime DATE := SYSDATE; BEGIN WHILE (SYSDATE - STime) < 0.006945 LOOP i := i + + 0.000001; End Loop; End; SQL_ID cujkdbu2npk0x, child number 0 DECLARE i NUMBER := 0; STime DATE := SYSDATE; BEGIN WHILE (SYSDATE - STime) < 0.006945 LOOP i := i + + 0.000001; End Loop; End; NOTE: cannot fetch plan for SQL_ID: cujkdbu2npk0x, CHILD_NUMBER: 0 Please verify value of SQL_ID and CHILD_NUMBER; It could also be that the plan is no longer in cursor cache (check v$sql_plan) Handle: 2152 User Time: 34.04S Sys Time: 0S ElapsedTime: 69S Priority: 8 ThreadState: In Run Queue PID:19 SPID:2152 SID:145 SERIAL#:12 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe INSERT INTO T1 SELECT CEIL(ABS(SIN(ROWNUM/9.9999)*10000)), 'This is the long description for this number '|| TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000)))... SQL_ID 6hxcgpp1rd1ag, child number 0 ------------------------------------- INSERT INTO T1 SELECT CEIL(ABS(SIN(ROWNUM/9.9999)*10000)), 'This is the long description for this number '|| TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000))) FROM (SELECT ROWNUM RN FROM DUAL CONNECT BY LEVEL<=10000), (SELECT ROWNUM RN FROM DUAL CONNECT BY LEVEL<=10000) Plan hash value: 643243249 ----------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Cost (%CPU)| Time | ----------------------------------------------------------------------------------- | 0 | INSERT STATEMENT | | | 4 (100)| | | 1 | LOAD TABLE CONVENTIONAL | | | | | | 2 | COUNT | | | | | | 3 | MERGE JOIN CARTESIAN | | 1 | 4 (0)| 00:00:01 | | 4 | VIEW | | 1 | 2 (0)| 00:00:01 | | 5 | COUNT | | | | | | 6 | CONNECT BY WITHOUT FILTERING | | | | | | 7 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | | 8 | BUFFER SORT | | 1 | 4 (0)| 00:00:01 | | 9 | VIEW | | 1 | 2 (0)| 00:00:01 | | 10 | COUNT | | | | | | 11 | CONNECT BY WITHOUT FILTERING| | | | | | 12 | FAST DUAL | | 1 | 2 (0)| 00:00:01 | -----------------------------------------------------------------------------------
The above was echoed to the command line window and also written to a logging file. So, how do we create this output? Save the following on the root of the C:\ drive as CPUHighLoadProcesses.vbs:
Const adNumeric=131 Const adParamInput=1 Const adCmdText=1 Const adVarChar=200 Dim i 'Loop counter for iterations Dim j 'Loop counter to find the previous stats for the thread Dim intInstance 'Index to the instance statistics Dim IntOldCSPerSec 'Previous value for Context Switches Per Second Dim intOldProcesses 'Previous value for the number of processes Dim intOldThreads 'Previous value for the number of threads Dim strSQL 'SQL to check WMI Win32_PerfRawData_PerfOS_System Dim strSQL2 'SQL to find the Oracle processes using WMI Win32_Process Dim strSQL3 'SQL to drill into the threads in the Oracle processes using WMI Win32_Thread Dim strSQL4 'SQL to find the Oracle session, SQL statement, and execution plan Dim strOut 'Data to be written to the text file Dim strComputer 'Oracle database server name, or . for the current computer Dim sglUMTime(20) 'User mode time in seconds for the Oracle instance Dim sglKMTime(20) 'Kernel mode time in seconds for the Oracle instance Dim sglWorkingSet(20) 'Working set memory size for the Oracle instance Dim sglPageFileUsage(20) 'Page/swap file usage for the Oracle instance Dim sglOUMTime(20) 'Previous user mode time in seconds for the Oracle instance Dim sglOKMTime(20) 'Previous kernel mode time in seconds for the Oracle instance Dim sglOldWorkingSet(20) 'Previous working set memory size for the Oracle instance Dim sglOldPageFileUsage(20) 'Previous page/swap file usage for the Oracle instance Dim objWMIService 'An object used to pass in the WMI calls Dim colItems 'Collection of processes running on the server Dim objItem 'An individual process running on the server Dim colThreads 'Collection of threads running in a process Dim objThread 'An individual thread running in a process Dim intThread 'Index to the previous values for the thread's statistics Dim intThreadCount(20) 'Maximum previous thread index for the instance Dim intThreadH(20,600) 'Thread handle Dim sglTUMTime(20,600) 'User mode time in seconds for the thread Dim sglTKMTime(20,600) 'Kernel mode time in seconds for the thread Dim sglTETime(20,600) 'Elapsed time in seconds for the thread Dim adsFile 'ADO stream object used to write out the log file Dim snpData 'ADO recordset used to query V$SESSION/V$SQL Dim comData 'ADO command object used to permit passing in bind variables for the V$SESSION/V$SQL query Dim snpDataPlan 'ADO recordset used to retrieve the execution plan for the session's SQL statement dim comDataPlan 'ADO command object used to permit passing in bind variables for the execution plan Dim dbDatabase 'ADO database connection object Dim intCheckIterations 'Number of times to check the instances Dim intDelayIterations 'Number of seconds to delay between iterations Dim sglThreadBusyPercent 'Percentage of the seconds in the iteration delay does a session need to consume to be examined Set snpData = CreateObject("ADODB.Recordset") Set comData = CreateObject("ADODB.Command") Set snpDataPlan = CreateObject("ADODB.Recordset") Set comDataPlan = CreateObject("ADODB.Command") Set dbDatabase = CreateObject("ADODB.Connection") strUsername = "MyUsername" strPassword = "MyPassword" strDatabase = "MyDB" intCheckIterations = 10 intDelayIterations = 60 sglThreadBusyPercent = 0.50 '50% dbDatabase.ConnectionString = "Provider=OraOLEDB.Oracle;Data Source=" & strDatabase & ";User ID=" & strUsername & ";Password=" & strPassword & ";" dbDatabase.Open 'Should verify that the connection attempt was successful, but I will leave that for someone else to code On Error Resume Next 'Allow continuing the script if an error happens 'Prepare the ADO Stream to write the data to the text file Set adsFile = CreateObject("ADODB.Stream") adsFile.Type = 2 adsFile.Charset = "iso-8859-1" adsFile.Open 'Prepare the SQL statements strSQL = "SELECT * FROM Win32_PerfRawData_PerfOS_System" strSQL2 = "SELECT * FROM Win32_Process Where Name like 'Oracle%'" strSQL3 = "SELECT * FROM Win32_Thread Where ProcessHandle=" With comData strSQL4 = "SELECT" & VBCrLf strSQL4 = strSQL4 & " P.PID," & VBCrLf strSQL4 = strSQL4 & " P.SPID," & VBCrLf strSQL4 = strSQL4 & " S.SID," & VBCrLf strSQL4 = strSQL4 & " S.SERIAL#," & VBCrLf strSQL4 = strSQL4 & " NVL(S.USERNAME,' ') USERNAME," & VBCrLf strSQL4 = strSQL4 & " NVL(S.MACHINE,' ') MACHINE," & VBCrLf strSQL4 = strSQL4 & " NVL(S.PROGRAM,' ') PROGRAM," & VBCrLf strSQL4 = strSQL4 & " S.SQL_ID," & VBCrLf strSQL4 = strSQL4 & " S.SQL_CHILD_NUMBER," & VBCrLf strSQL4 = strSQL4 & " NVL(SQL.SQL_TEXT,' ') SQL_TEXT" & VBCrLf strSQL4 = strSQL4 & "FROM" & VBCrLf strSQL4 = strSQL4 & " V$PROCESS P," & VBCrLf strSQL4 = strSQL4 & " V$SESSION S," & VBCrLf strSQL4 = strSQL4 & " V$SQL SQL" & VBCrLf strSQL4 = strSQL4 & "WHERE" & VBCrLf strSQL4 = strSQL4 & " P.SPID=?" & VBCrLf strSQL4 = strSQL4 & " AND P.ADDR=S.PADDR" & VBCrLf strSQL4 = strSQL4 & " AND S.SQL_ID = SQL.SQL_ID(+)" & VBCrLf strSQL4 = strSQL4 & " AND S.SQL_CHILD_NUMBER = SQL.CHILD_NUMBER(+)" & VBCrLf strSQL4 = strSQL4 & "ORDER BY" & VBCrLf strSQL4 = strSQL4 & " S.USERNAME," & VBCrLf strSQL4 = strSQL4 & " P.PROGRAM" .Parameters.Append .CreateParameter("spid", adNumeric, adParamInput, 12, 0) .CommandText = strSQL4 .CommandType = adCmdText .CommandTimeout = 30 .ActiveConnection = dbDatabase End With With comDataPlan strSQL4 = "SELECT" & VBCrLf strSQL4 = strSQL4 & " *" & VBCrLf strSQL4 = strSQL4 & "FROM" & VBCrLf strSQL4 = strSQL4 & " TABLE(DBMS_XPLAN.DISPLAY_CURSOR(?, ?, 'TYPICAL'))" & VBCrLf .Parameters.Append .CreateParameter("sql_id", adVarchar, adParamInput, 20, "") .Parameters.Append .CreateParameter("child_number", adNumeric, adParamInput, 12, 0) .CommandText = strSQL4 .CommandType = adCmdText .CommandTimeout = 30 .ActiveConnection = dbDatabase End With strComputer = "." ' the . indicates the local computer Set objWMIService = GetObject("winmgmts:{impersonationLevel=impersonate}!\\" & strComputer & "\root\CIMV2") IntOldCSPerSec = 0 For intInstance = 1 to 20 sglOUMTime(intInstance) = 0 sglOKMTime(intInstance) = 0 sglOldWorkingSet(intInstance) = 0 sglOldPageFileUsage(intInstance) = 0 intThreadCount(intInstance) = 0 intThreadH(intInstance,1) = 0 sglTUMTime(intInstance,1) = 0 sglTKMTime(intInstance,1) = 0 sglTETime(intInstance,1) = 0 Next For i = 1 to intCheckIterations 'Number of iterations Set colItems = objWMIService.ExecQuery(strSQL,"WQL",48) For Each objItem in colItems strOut = Now() & " Processes: " & objItem.Processes strOut = strOut & " Threads: " & objItem.Threads strOut = strOut & " C. Switches: " & objItem.ContextSwitchesPersec - IntOldCSPerSec strOut = strOut & " Q. Length: " & objItem.ProcessorQueueLength 'Write to screen Wscript.Echo strOut 'Write to log file adsFile.WriteText(strOut & vbCrLf) IntOldCSPerSec = objItem.ContextSwitchesPersec intOldProcesses = objItem.Processes intOldThreads = objItem.Threads Next Set colItems = Nothing Set colItems = objWMIService.ExecQuery(strSQL2,"WQL",48) intInstance = 0 For Each objItem in colItems intInstance = intInstance + 1 sglUMTime(intInstance) = Round(objItem.UserModeTime/10000000, 2) sglKMTime(intInstance) = Round(objItem.KernelModeTime/10000000, 2) sglWorkingSet(intInstance) = Round(objItem.WorkingSetSize/1048576, 2) sglPageFileUsage(intInstance) = Round(objItem.PageFileUsage/1048576, 2) strOut = "Instance: " & objItem.CommandLine & vbCrLf strOut = strOut & " User Time: " & Round(sglUMTime(intInstance) - sglOUMTime(intInstance),2) & "S" strOut = strOut & " Sys Time: " & Round(sglKMTime(intInstance) - sglOKMTime(intInstance),2) & "S" strOut = strOut & " Memory: " & sglWorkingSet(intInstance) & "MB" strOut = strOut & " Page File: " & sglPageFileUsage(intInstance) & "MB" & vbCrLf Set colThreads = Nothing Set colThreads = objWMIService.ExecQuery(strSQL3 & cStr(objItem.ProcessID),"WQL",48) For Each objThread in colThreads 'Find the statistics for thread from the previous iteration's statistics intThread = intThreadCount(intInstance) + 1 For j = 1 to intThreadCount(intInstance) If intThreadH(intInstance,j) = objThread.Handle Then intThread = j Exit For End If Next If intThreadH(intInstance,intThread) = 0 Then 'This is a new thread that was not captured before intThreadH(intInstance,intThread) = objThread.Handle If intThreadCount(intInstance) < intThread Then intThreadCount(intInstance) = intThread End If End If If (cSng(Round(objThread.UserModeTime/1000,2)-sglTUMTime(intInstance,intThread)+ _ Round(objThread.KernelModeTime/1000,2)-sglTKMTime(intInstance,intThread)) / _ intDelayIterations) >= sglThreadBusyPercent Then strOut = strOut & " Handle: " & cStr(objThread.Handle) strOut = strOut & " User Time: " & Round((Round(objThread.UserModeTime/1000,2)-sglTUMTime(intInstance,intThread)),2) & "S" strOut = strOut & " Sys Time: " & Round((Round(objThread.KernelModeTime/1000,2)-sglTKMTime(intInstance,intThread)),2) & "S" strOut = strOut & " ElapsedTime: " & Round((Round(objThread.ElapsedTime/1000,2)-sglTETime(intInstance,intThread)),2) & "S" strOut = strOut & " Priority: " & objThread.Priority strOut = strOut & " ThreadState:" Select Case objThread.ThreadState Case 0 strOut = strOut & " Initialized" Case 1 strOut = strOut & " In Run Queue" Case 2 strOut = strOut & " Running" Case 3 strOut = strOut & " Preparing to Run" Case 4 strOut = strOut & " Terminated" Case 5 strOut = strOut & " Idle" Case 6 strOut = strOut & " Non-CPU Wait Event:" 'See http://msdn.microsoft.com/en-us/library/aa394494(VS.85).aspx Select Case objThread.ThreadWaitReason Case 0 strOut = strOut & "Executive" Case 1 strOut = strOut & "FreePage" Case 2 strOut = strOut & "PageIn" Case 3 strOut = strOut & "PoolAllocation" Case 4 strOut = strOut & "ExecutionDelay" Case 5 strOut = strOut & "FreePage" Case 6 strOut = strOut & "PageIn" Case 7 strOut = strOut & "Executive" Case 8 strOut = strOut & "FreePage" Case 9 strOut = strOut & "PageIn" Case 10 strOut = strOut & "PoolAllocation" Case 11 strOut = strOut & "ExecutionDelay" Case 12 strOut = strOut & "FreePage" Case 13 strOut = strOut & "PageIn" Case 14 strOut = strOut & "EventPairHigh" Case 15 strOut = strOut & "EventPairLow" Case 16 strOut = strOut & "LPCReceive" Case 17 strOut = strOut & "LPCReply" Case 18 strOut = strOut & "VirtualMemory" Case 19 strOut = strOut & "PageOut" Case 20 strOut = strOut & "Unknown" Case Else strOut = strOut & objThread.ThreadWaitReason End Select Case 7 strOut = strOut & " Unknown" Case Else strOut = strOut & objThread.ThreadState End Select strOut = strOut & vbCrLf comData("spid") = objThread.Handle Set snpData = comData.Execute If Not(snpData Is Nothing) Then If Not(snpData.EOF) Then strOut = strOut & " PID:" & snpData("pid") strOut = strOut & " SPID:" & snpData("spid") strOut = strOut & " SID:" & snpData("sid") strOut = strOut & " SERIAL#:" & snpData("serial#") strOut = strOut & " USERNAME:" & snpData("username") strOut = strOut & " MACHINE:" & snpData("machine") strOut = strOut & " PROGRAM:" & snpData("program") & vbCrLf strOut = strOut & " " & snpData("sql_text") & vbCrLf If Not(IsNull(snpData("sql_id"))) Then comDataPlan("sql_id") = snpData("sql_id") comDataPlan("child_number") = snpData("sql_child_number") Set snpDataPlan = comDataPlan.Execute If Not(snpDataPlan Is Nothing) Then strOut = strOut & vbCrLf Do While Not(snpDataPlan.EOF) strOut = strOut & " " & snpDataPlan(0) & vbCrLf snpDataPlan.MoveNext Loop snpDataPlan.Close End If strOut = strOut & vbCrLf End If End If snpData.Close End If End If sglTUMTime(intInstance,intThread) = Round(objThread.UserModeTime/1000,2) sglTKMTime(intInstance,intThread) = Round(objThread.KernelModeTime/1000,2) sglTETime(intInstance,intThread) = Round(objThread.ElapsedTime/1000,2) Next strOut = strOut & vbCrLf 'Write to screen Wscript.Echo strOut 'Write to log file adsFile.WriteText(strOut & vbCrLf) sglOUMTime(intInstance) = Round(objItem.UserModeTime/10000000, 2) sglOKMTime(intInstance) = Round(objItem.KernelModeTime/10000000, 2) sglOldWorkingSet(intInstance) = Round(objItem.WorkingSetSize/1048576, 2) sglOldPageFileUsage(intInstance) = Round(objItem.PageFileUsage/1048576, 2) Next 'Wait intDelayIterations seconds before sampling again Wscript.Sleep intDelayIterations * 1000 Next adsFile.SaveToFile "C:\CPUHighLoadProcesses.txt", 2 adsFile.Close dbDatabase.Close Set snpData = Nothing Set comData = Nothing Set snpDataPlan = Nothing Set comDataPlan = Nothing Set dbDatabase = Nothing Set adsFile = Nothing
If you decide to use the above script, test it very carefully. There may be one or two typos or logic errors. If you have administrator rights on the server, the script can be executed remotely (it does not need to be run directly on the server). WMI queries are given a very low priority, so if the CPU run queue is long, the script may appear to hang for a long time. To run the script, open a command line window and type:
cscript C:\CPUHighLoadProcesses.vbs
WMI queries are very powerful, as demonstrated by the above script.
—
Update: 1.5 hours before this blog article is scheduled to appear:
{RANT}
After I wrote the above script and this and the previous blog articles I stumbled upon the following very recent news article that states the following:
dba-oracle.com/t_display_background_processes_windows.htm
“In Windows, the ‘thread’ model is used, and Oracle dispatches his own background tasks within the domain of the single process, oracle.exe. Hence, you cannot see any background processes from the Windows OS (but you can see listener process and parallel query slaves).”
OK, forget about my script, because the quote directly above states that it is not possible. Someone please call Oracle Corp. and tell them that their Oracle Administration Assistant for Windows needs to be removed from the documentation because what it shows is simply not possible. Did I mention that I dislike being confused?
{/RANT}
Very usable info.
Regards
Greg
[…] Charles Hooper-Drilling into Session Detail from the Operating System – On the Windows Platform 2 […]