One of the hardest things that I found when starting out developing in Oracle was working out what Oracle was doing with my code. I followed normal development practices, assembled my code into a logical sequence of actions, deployed and ran it… and then Oracle was like a black box until it finished and I could check the results of the process. At times I would be developing long running processes that I would want to monitor as it was executing. So, how should I go about this I wondered?
Not knowing much about the internals of Oracle I started to instrument my code. Before and after any major activity I would write out a message to a log table, which gave me valuable information as to the path that my code took and how long it spent executing the step. Autonomous transactions permitted me to view my log messages as they were generated, which is a huge benefit when tracing an executing process in real time. I still instrument my code and maintain that it is the single most important practice for general problem resolution.
However, while instrumentation gave me insights into my code it didn’t help too much when it came down to working out what a long running query was up to. It was then that I had to delve into the Oracle black box. Thankfully, once I got started I found out that Oracle is quite forthcoming with details. If anything, the amount of detail available can be overwhelming. For my purpose, I simply wanted to observe what my process was up to and what queries it was running.
So, for now, I’m going to describe how I got started by simply identifying a running session and figuring out the details of the SQL that was being executed. Once I was able to track down details about actual SQL execution then I had gained further insights into my processes and why they might not be behaving as I expected.
Session Identification
The first step to monitoring a process is to determine the database session that it is running under. The internal view v$session is a listing of all sessions within the database so the process is one of those entries… but which one? Well, unfortunately there’s no single, simple answer and some detective work is needed to filter down the list to the process entry.
Some column filters that are typically useful are:
- STATUS – filter for a value of ACTIVE
- USERNAME – filter for the account name that the proces is run from within
- OSUSER – filter for the name of the network account that is being used to run the process
- MACHINE – the name of the remote computer that is being used to run the process
As an example, the following query may be used to identify active sessions being run by a specific network user:
SELECT * FROM v$session WHERE status = 'ACTIVE' AND osuser = :user
From the above filters it’s generally possible to narrow the list of sessions down to a handful of candidates even in a busy system. Problems can still arise though when connection pooling is used by application middle tiers. With such architectures it can be difficult to pinpoint the specific session of interest. The use of MODULE, ACTION and CLIENT_INFO settings can be invaluable in such scenarios but only if the application has been written to utilise them (do I really need to emphasise this point again?). If the database is set up in a shared server configuration then this would present yet another hurdle.
Assuming that the session running the process has been identified then the details within v$session, as of Oracle 10g, provide critical pieces of information of what the process is doing, including:
- SQL_ID – the ID of the SQL statement that is currently being executed
- EVENT – the event that the session is currently waiting on. Also provided are the event parameter values (P1, P2, P3) for further diagnoses
- BLOCKING_SESSION – The SID of the session currently blocking the process
To get the details of the SQL being executed then all we need is the SQL_ID and SQL_CHILD_NUMBER values…
SQL Statement
Once the SQL_ID and SQL_CHILD_NUMBER that the process is executing has been obtaned from v$session then finding the SQL statement is quite trivial. The following simple query against v$sql will yield this information:
SELECT sql_fulltext FROM v$sql WHERE sql_id = :sql_id AND child_number = :sql_child_number
Note however that the SQL_FULTEXT column is a CLOB data type, which may present problems for certain database client programs. The SQL_TEXT column can be used instead to obtain the first 1,000 bytes of the full text.
So, we’ve now progressed from identifying the session that the process is running under to identifying the SQL that it’s running. The next check is whether it’s executing in a manner that we expected…
SQL Execution Plan
During development I general check that the execution plan of any SQL is going to be reasonable. Obviously the criteria of what is “reasonable” is variable depending on the type of statement. However, after deployment it may be that either the execution plan turns out to be not appropriate or Oracle chooses to use a plan that is different to what I expected. In any case, it’s worthwhile checking that the actual execution plan of the SQL being executed. The SQL_ID and SQL_CHILD_NUMBER from v$session are used to obtain that:
SELECT * FROM TABLE(dbms_xplan.display_cursor(:sql_id,:sql_child_number))
The plan obtained from the above query can then be used to compare to the plan obtained during development to see if there are any significant changes.
It may be that the plan is as expected but the query still seems to take an excessive amount of time. In this situation it may be possible to check the query progress via SQL Monitor, which provides an execution breakdown of each step of the plan.
The above procedure is aimed at helping a newcomer to Oracle to work out some basic details of what an executing process is doing. v$session provides details of the currently executing SQL statement and v$sql gives us the actual statement. Obviously this approach is only effective for processes running for a reasonable length of time. Regular, real time polling (combined with any process instrumentation, of course) is required in order to get a reasonable appreciation of what a process is up to over its total execution.
However, it is regularly the case that the process is already well underway or even completed before the question is asked “what did that process do?”, often with the secondary question of “… and why did it take so long?”. So, is it possible to see what a process got up to after it has finished execution? This will form the basis of a future post…
Mark Hoxey 