Basic Performance Analysis using AWR data

I've previously covered a number of queries that can be combined together to pull out key statistics from the Oracle AWR data for each snapshot it makes, which you could use to analyse the performance of a system. One example would be to use this to look at how the workload changes during the day, and to identify the period of peak activity. Another use would be to see if there were any periods experiencing significantly higher waits than at other times.

I'll now go through how you can use some of the AWR data to do an overall performance analysis of a system. But before we do that, we need to review some basics on performance tuning, just to clarify some things and avoid potential confusion.

Performance Tuning Basics

I'm of the same school of tuning as people like Cary Millsap and Jeff Holt and others - generally speaking you should be tuning specific performance problems as experienced by individual Oracle sessions, and not tuning the system as a whole. This is because any "improvements" you make to the system that do not benefit the slow sessions are completely wasted and pointless. For instance, the system may be experiencing slow disk I/O's, but it might be that the reported slow interactive response time by some users is due to very high CPU usage resulting from a poor execution plan for the particular SQL statement that session is executing. Making the disk I/O's happen quicker might "improve" things for the system as a whole, but it will have no impact at all on the CPU bound SQL statement that is the cause of slow response times on an end user's screen.

That said, there are times where system level tuning is appropriate or when you can only do system level tuning, and that is where AWR can help as it gathers system wide activity data. For session level tuning you need to look elsewhere - such as ASH (Active Session History) or using SQL Trace.

There are some big assumptions being made when we do system level tuning:

• All sessions are executing the same or similar SQL statements
  • So a system wide "average" view across all sessions is valid
• Any "poor performance" on the system impacts all sessions equally
  • So even one rogue SQL statement can slow down all other SQL statements being executed from other sessions
• The system is under a high enough load that performance problems are due to interactions between the SQL statements
  • It is assumed that poorly performing individual SQL statements would have been identified earlier under initial testing

Providing these assumptions or similar are true, then you can do system level tuning.

System Level Tuning Measurements

A computer system exists to do work, and its performance is really about how long it takes to to that work and which resources it uses while doing it. Performance is an issue when a task takes too long to complete.

We need to measure both sides of this – the input work requests, and the output usage of the system resources that results. We can only do performance tuning properly when we know both of these, as this lets us see the impact of any changes we make - does resource usage go down or not for the same input workload?

Measuring the input workload is best done at business or application level transactions. And this is best achieved by instrumenting the application software itself to record both the type of transaction it is performing and the elapsed time it takes when submitted. However, very few applications if any are instrumented this way.

This leaves a database level measurement as the only viable and consistently available way of recording the input workload, and in my view the best available measurement is the number of SQL statements executed per second. While this is very imperfect as a measure of the input workload, it is the nearest we are going to get to it, and all input application transactions result in SQL statements being executed. So it does correlate with input workload.

For a measurement of workload on the system - the output resulting from the execution of the SQL statements - the best measurement is probably Average Active Sessions. AAS is simply the Database Time ("DB Time" from System Time Model) divided by elapsed time for the period over which Database Time was measured. The Database Time value is a measurement of the amount of elapsed time sessions were active executing SQL statements, and includes both active execution time (running on a CPU) and waiting time (for disk I/O or any other wait event). AAS indicates how many sessions were active at the same time executing SQL statements i.e. the level of concurrency on your system.

AAS correlates with the number of CPU's on your system - if all SQL statements executed with no waiting at all they would only use up CPU resource and your transaction rate would be limited by the number of CPU's in the system. If AAS is less than the number of CPU's in your system then you are not reaching capacity. If AAS is close to or more than the number of CPU's then you have an overloaded system and waiting of some form or another is occurring.

To make real use of the AAS value we also want to know the percentage of time spent waiting during each period i.e. total wait time as a percentage of database active time (DB time again). The Percentage Wait (which I label Wait%) indicates the efficiency of the SQL statement execution - if this waiting was eliminated then that wait time would be removed from the elapsed time of each SQL statement executed. This is only relevant when AAS is high enough. When the level of concurrency is very low you can get various anomalies, and there will always be some waiting somewhere. Again remember the assumptions I stated earlier - the system must be under a high enough load to experience performance problems due to the combined workload itself.

That's it - 3 simple measurements should be enough to tell you whether your system is overloaded or not, and whether it is performing efficiently. These can be easily extracted from AWR (see later in this post), and can graphed in your favourite spreadsheet tool to spot trends and anomalies.

Using these measurements

If you have a system wide bottleneck / capacity limit then checking on the total system resource usage during a period of time will hopefully identify any such bottlenecks. As stated, if AAS is high enough (I would say more than half of the number of CPU's), and the Wait% is also high (say 50% or more), then you have poor performance and it can be improved.

At this point I would use the expanded version of the AWR query that I have built up over the previous posts to get all of the data out of AWR for each snapshot, and again into a spreadsheet or something else. Within this AWR data is a breakdown of the Oracle Wait Time by Wait Class, which tells you which "type" of wait was consuming most of the wait time. This can either primarily be Disk (I/O), Network, Cluster, Commit (Redo), or Concurrency (locking).

Knowing the wait class you can then query AWR for SQL statement execution and sum them over the wait class identified earlier, and sort by the wait class time summed. I showed how to do this in my previous post, summing the number of disk reads per SQL statement executed in each snapshot. This way you easily get to see the top SQL by that wait type, and see how much time they spent waiting relative to the total wait time.

Equally you could just do all SQL statements by their total wait time, to see those that experienced the worst waits whatever type of wait they were. Wait time for a SQL statement would be calculated as its Elapsed time minus the CPU time.

AWR System Performance Query

Here is a query that gives you just the 3 key measurements mentioned before for a system from the AWR data. It reports all the measurements for yesterday - modify the date range constraint to report on different periods.

set feedback off
set verify off
set linesize 1000
set trimout on
set trimspool on
--
col snap_time           format a15      heading 'SNAP TIME'
col user_calls_sec      format 9,990    heading 'UCALL/S'
col aas                 format 90.0     heading 'AAS'
col wait_pct            format 990.0    heading 'WAIT%'
--
with
snaps as 
(select snap_id
      , dbid
      , end_snap_time
      , snap_interval
      , extract (second from snap_interval) 
       + (extract (minute from snap_interval) 
          + (extract (hour from snap_interval)
             + (extract (day from snap_interval) * 24)
             ) * 60
          ) * 60 snap_duration
  from (select csnaps.snap_id
             , csnaps.dbid
             , min (csnaps.end_interval_time) end_snap_time
             , min (csnaps.end_interval_time) - min (csnaps.begin_interval_time) snap_interval
          from dba_hist_snapshot csnaps
         group by csnaps.snap_id, csnaps.dbid
       )
) -- snaps
, systimes as 
-- One row per Database Time Model with change in value between snapshots
(select systime.snap_id
      , systime.dbid
      , systime.stat_name
      , sum (systime.value - psystime.value) value
         from dba_hist_sys_time_model systime, dba_hist_sys_time_model psystime
        where systime.snap_id = psystime.snap_id + 1
          and systime.dbid = psystime.dbid
          and systime.instance_number = psystime.instance_number
          and systime.stat_id = psystime.stat_id
-- Assume if stat_id the same so is the stat_name
        group by systime.snap_id, systime.dbid, systime.stat_name
) -- systimes
, sysstats as 
-- One row per System Statistic with change in value between snapshots
(select sysstat.snap_id
      , sysstat.dbid
      , sysstat.stat_name
      , sum (sysstat.value - psysstat.value) value
         from dba_hist_sysstat sysstat, dba_hist_sysstat psysstat
        where sysstat.snap_id = psysstat.snap_id + 1
          and sysstat.dbid = psysstat.dbid
          and sysstat.instance_number = psysstat.instance_number
          and sysstat.stat_id = psysstat.stat_id
-- Assume if stat_id the same so is the stat_name
        group by sysstat.snap_id, sysstat.dbid, sysstat.stat_name
) -- sysstats
, syswaits as 
-- One row for total wait time, plus break down into major wait classes, and events
(select sysevent.snap_id
      , sysevent.dbid
      , sum (sysevent.time_waited_micro - psysevent.time_waited_micro) time_waited_micro
      , sum (sysevent.total_waits - psysevent.total_waits) wait_count
   from dba_hist_system_event sysevent, dba_hist_system_event psysevent
  where sysevent.snap_id = psysevent.snap_id + 1
    and sysevent.dbid = psysevent.dbid
    and sysevent.instance_number = psysevent.instance_number
    and sysevent.event_id = psysevent.event_id
    and sysevent.wait_class != 'Idle'  -- Ignore Idle wait events
  group by sysevent.snap_id
      , sysevent.dbid
) -- syswaits
select to_char (snaps.end_snap_time, 'DD/MM/YY HH24:MI') snap_time
     , (user_calls_st.value / snaps.snap_duration)              user_calls_sec
     , (dbtime.value / 1000000)       / snaps.snap_duration     aas
     , (100 * syswaits.time_waited_micro / dbtime.value)        wait_pct
  from snaps
     join (select * from systimes where stat_name = 'DB time') dbtime
       on snaps.snap_id = dbtime.snap_id and snaps.dbid = dbtime.dbid
     join syswaits
       on snaps.snap_id = syswaits.snap_id and snaps.dbid = syswaits.dbid
     join (select * from sysstats where stat_name = 'user calls') user_calls_st
       on snaps.snap_id = user_calls_st.snap_id and snaps.dbid = user_calls_st.dbid
 where snaps.end_snap_time between 
       (trunc (sysdate) - 1) and (trunc (sysdate))
 order by snaps.end_snap_time
/
--
set feedback on
set lines 80

AWR Reporting #6 - SQL Statements

This is the last of the main set of posts on this topic. As for the last post, I'll try and keep this brief and post the SQL involved.

Another data set we can look at is on SQL statements i.e. statistics collected by AWR on individual SQL statements, not overall totals. AWR snapshots SQL statements from V$SQLSTAT to DBA_HIST_SQLSTAT for per SQL statement statistics.

As before we could use the technique of subtracting the values from the previous snapshot from the values of the current snapshot to get the change in value between the snapshots. Unfortunately this runs into issues as not all SQL statements may be present in both snapshots, and SQL statements can be flushed out of the library cache in the SGA and then added back in again later so their statistics have been reset in-between.

Luckily Oracle has solved this problem for us and provided a set of DELTA columns for the most important statistics giving us just what we want. Also this avoids the need to join back to the previous snapshot to calculate the change between the snapshots - the DELTA columns are already the change in value from the previous snapshot.

The main query then to extract useful statistics per SQL statement per database per snapshot is:

select sqlstat.snap_id
     , sqlstat.dbid
     , sqlstat.sql_id
     , sum (sqlstat.elapsed_time_delta)  sql_time
     , sum (sqlstat.executions_delta) sql_execs
     , sum (sqlstat.disk_reads_delta) sql_reads
  from dba_hist_sqlstat sqlstat
 group by sqlstat.snap_id
     , sqlstat.dbid
     , sqlstat.sql_id

We cannot use this query directly in our current main AWR summary query as we are getting multiple data rows per snapshot - one per SQL statement captured by that snapshot. The obvious thing to do is to sum the values over all of the SQL statements executed in that snapshot to produce one set of values per snapshot. Unfortunately this doesn't really give us anything that useful - we already have data values from AWR for these statistics across the whole system (SQL execution time, number of SQL statements executed, and number of disk reads), and when added up across all the SQL statements it doesn't help us see if there are any anomalies within the SQL statement themselves.

A better use for this query is to run it separately within another query that instead groups by SQL_ID and sums over multiple snaphots e.g. all snapshots in one day. This is a useful way of seeing which particular SQL statements put a greater load on the system than other SQL statements. "Load" could be number of executions, CPU used, disk reads, or some other measurement.

For example, one system I was looking at recently was doing a lot of disk reads and I could see that there were a number of table scans occurring. So I wanted to identify the SQL statements causing these table scans i.e. the SQL statements with the highest disk reads. By summarising over a whole day I could ensure that I was looking at the worst offenders who were executed multiple times during the day, and not a bad query only executed once.

The following query reports SQL statements captured by AWR yesterday ("sysdate - 1" truncated to midnight) sorted by total number of disk reads. The "sql_reads > 100000" is a filter so that not all SQL statements are listed, only those with a significant number of disk reads - you can increase or decrease this threshold based on how active your system is. You may want to start higher at a million and then reduce it by a factor of 10 until you get enough SQL statements listed.

with 
snaps as 
(select csnaps.snap_id
      , csnaps.dbid
      , min (csnaps.end_interval_time) end_snap_time
      , min (csnaps.end_interval_time) - min (csnaps.begin_interval_time) snap_interval
   from dba_hist_snapshot csnaps
  group by csnaps.snap_id, csnaps.dbid
) -- snaps
, sqlstats as
(
[insert previous query here]
)
select sqlstats.sql_id
     , sum (sqlstats.sql_reads)  sql_reads
     , sum (sqlstats.sql_execs)  sql_execs
     , sum (sqlstats.sql_time) / 1000000 sql_time
  from snaps
     join sqlstats
       on snaps.snap_id = sqlstats.snap_id and snaps.dbid = sqlstats.dbid
 where snaps.end_snap_time between 
       (trunc (sysdate) - 1) and (trunc (sysdate))
   and sql_reads > 100000
 group by sqlstats.sql_id
 order by sql_reads desc
/

Note that the time values are in microseconds and so must be divided by one million to output them as seconds.

A further optimization to this query is to restrict it to the main working hours, say 8am to 6pm:

   and extract (hour from snaps.end_snap_time) between 8 and 17 -- 8:00 to 17:59

This avoids issues with any overnight batch jobs you may be running or the Oracle default job to update stale statistics on database objects (which does do a lot of disk reads).

When I used this I was able to identify about 4 SQL statements responsible for about 25% of the disk reads on the system, each having a relatively low execution count - under 100 each for millions of disk reads in total. Each was clearly doing full table scans, which was validated by checking the execution plans of each - there is an AWR report supplied with Oracle that reports this information for a SQL statement across a number of snapshots (awrsqrpt.sql).

Now that I knew the top contributors to disk reads on the system I was able to investigate each SQL statement individually and work out changes to improve their execution. This was a mixture of extra indexes, SQL rewrites and other database changes.

AWR Summary Reporting #5 - System Statistics

So far our AWR report query shows overall duration between two consecutive snapshots, database time (i.e. doing work), SQL execution time (may be lower), total wait time, wait time by class, and some common specific wait events. We know how busy the database was and how much time it spent waiting and on what. Now I want to add in some more data captured by the AWR on system activity. This series is dragging on a bit, so I'm going to try and keep this one shorert and just get it posted out.

AWR snapshots V$SYSSTAT into DBA_HIST_SYSSTAT. This contains individual system statistics with cumulative running totals for each. These are stored as Name / Value pairs in each table. Most statistics are just counts of event occurrences e.g. "physical reads", "physical writes", but some have been added that are time values. This lets you calculate average time per event when you have the corresponding event count as well. Beware that many of the "time" values are in odd units, such as hundredths of seconds (1/100 second), and will need to be adjusted if you want to report in standard units of time.

Statistics recorded include the following, which I've tried to group together into related sets. The details don't really matter on these, as the point of these AWR Summary Reports is to pull out as much as we can at once from a database for later analysis. Some of these statistics might only be relevant in specific scenarios - but by pulling them out at the same time as others, we already have them when they are needed.

• SQL statement execution - how many? Elapsed Time is in the Database Time Model data set
  • "execute count" - SQL statements executed, both user and recursive
  • "user calls" = Number of user calls such as login, parse, fetch, or execute.
  • "recursive calls"
• Transactions = units of work = groups of related SQL statements
  • "user commits" = commit count
  • "user rollbacks" = rollback count = abandoned transactions
• Average Redo Write Time - how long to write to the redo log?
  • "redo write time" = Total write time in 100'ths of seconds aka. 10's of milliseconds
  • "redo writes" = Number of redo writes that occurred
  • Also "redo blocks written" - Divide by "redo writes" to get average blocks per write
  • Can break redo writes down into those due to a "commit" and others (log buffer full enough to warrant a write)
  • Commit == Redo Synch -> "redo synch time" / "redo synch writes"
• Disk I/O - how many disk operations? Elapsed time is in the Wait Events data set
  • "physical reads" = Physical Reads
  • "physical writes" - Physical Writes
• Logical reads = "consistent gets" + "db block gets"
  • Note that "session logical reads" is defined as 'The sum of "db block gets" plus "consistent gets"', but might also include logical reads from 'process private memory'.

Because the statistics are stored as Name / Value pairs, each statistic is in a separate row rather than a separate column in the same row as other statistics. We can use a sub-query that retrieves each change in statistic value for each AWR snapshot, and then use this within the main query in an in-line view for each statistic with an appropriate alias name.

, sysstats as 
-- One row per System Statistic with change in value between snapshots
(select sysstat.snap_id
      , sysstat.dbid
      , sysstat.stat_name
      , sum (sysstat.value - psysstat.value) value
         from dba_hist_sysstat sysstat, dba_hist_sysstat psysstat
        where sysstat.snap_id = psysstat.snap_id + 1
          and sysstat.dbid = psysstat.dbid
          and sysstat.instance_number = psysstat.instance_number
          and sysstat.stat_id = psysstat.stat_id
-- Assume if stat_id the same so is the stat_name
        group by sysstat.snap_id, sysstat.dbid, sysstat.stat_name
) -- sysstats

select to_char (snaps.end_snap_time, 'DD/MM/YY HH24:MI') snap_time
...
     , execs.value executions
     , user_calls_st.value user_calls
     , user_commits_st.value user_commits
     , redo_write_st.value redo_writes
     , redo_time_st.value / 100 redo_write_time
     , phys_reads.value physical_reads
     , phys_writes.value physical_writes
     , table_scans_st.value table_scans
from
...
     join (select * from sysstats where stat_name = 'execute count') execs
       on snaps.snap_id = execs.snap_id and snaps.dbid    = execs.dbid
     join (select * from sysstats where stat_name = 'user calls') user_calls_st
       on snaps.snap_id = user_calls_st.snap_id and snaps.dbid = user_calls_st.dbid
     join (select * from sysstats where stat_name = 'user commits') user_commits_st
       on snaps.snap_id = user_commits_st.snap_id and snaps.dbid  = user_commits_st.dbid
     join (select * from sysstats where stat_name = 'redo writes') redo_write_st
       on snaps.snap_id = redo_write_st.snap_id and snaps.dbid  = redo_write_st.dbid
     join (select * from sysstats where stat_name = 'redo write time') redo_time_st
       on snaps.snap_id = redo_time_st.snap_id and snaps.dbid  = redo_time_st.dbid
     join (select * from sysstats where stat_name = 'physical reads') phys_reads
       on snaps.snap_id = phys_reads.snap_id and snaps.dbid    = phys_reads.dbid
     join (select * from sysstats where stat_name = 'physical writes') phys_writes
       on snaps.snap_id = phys_writes.snap_id and snaps.dbid  = phys_writes.dbid
     join (select * from sysstats where stat_name = 'table scans (long tables)') table_scans_st
       on snaps.snap_id = table_scans_st.snap_id and snaps.dbid  = table_scans_st.dbid
...

This means that we can now correlate overall system performance (Database Time and Wait Time) against other activities on the system and drill down further. Using the template given above you can extract any System Statistic you are interested in, and it is easy to add other ones in the future when you need them.

AWR Summary Reporting #4 - More Waits

Given the previous sub-query for total wait times including class level waits from the AWR snapshot data, we are going to extend that particular sub-query in order to add some extra wait event data items to it. This will give us a further breakdown of what the major wait events were, and how much time was spent waiting versus doing real work. The upside to these changes are that we will be able to pull out some other wait event times from the AWR snapshots in the same query, for little extra cost or increase in complexity. The downside is that the number of data items being selected for output will increase a lot, and this may start to look like a "mother of all database monitoring queries". However, the query itself is not more complex, and the intention is to get as much data as we can from each AWR snapshot in one hit to allow us to analyse it later outside Oracle (typically in a spreadsheet).

But before we do that I want to refactor that sub-query to make some of the later additions to it easier and simpler. Remember that we had just one sub-query, with the wait time always being calculated by subtracting the current snapshot's wait time from the previous snapshot's time. I want to refactor this by pushing this subtraction down into a nested sub-query, so that the rest of the wait sub-query becomes simpler.

So before we had elements like:

, sum (sysevent.time_waited_micro - psysevent.time_waited_micro) all_wait_time
, sum (decode (sysevent.wait_class, 'Commit', (sysevent.time_waited_micro - psysevent.time_waited_micro), 0)) commit_time

The refactor changes this to:

, syswaits as 
-- One row for total wait time, plus break down into major wait classes, and events
(select syswaitevents.snap_id
      , syswaitevents.dbid
      , sum (syswaitevents.time_waited_micro) all_wait_time
      , sum (decode (syswaitevents.wait_class, 'Commit', syswaitevents.time_waited_micro, 0)) commit_time
...
   from 
        (select sysevent.snap_id
              , sysevent.dbid
              , sysevent.wait_class
              , sysevent.event_name
              , sum (sysevent.time_waited_micro - psysevent.time_waited_micro) time_waited_micro
              , sum (sysevent.total_waits - psysevent.total_waits) wait_count
           from dba_hist_system_event sysevent, dba_hist_system_event psysevent
          where sysevent.snap_id = psysevent.snap_id + 1
...
            group by sysevent.snap_id, sysevent.dbid, sysevent.wait_class, sysevent.event_name
        ) syswaitevents
  group by syswaitevents.snap_id
         , syswaitevents.dbid
) -- syswaits

The key points are:

• The inner sub-query groups by wait class and individual event name, as well as by snapshot and database id, and sums the wait time to this granularity.
• It also sums the total occurrences of each wait event, for further use in the outer query.
• The outer sub-query can now just refer to "syswaitevents.time_waited_micro" as the elapsed wait time, as the subtraction between the current and previous snapshot values are done in the inner sub-query.
• The outer sub-query still does the "decode" of the class name to extract individual sums for each class desired

Previously I said that there were too many individual events to report them all - around 100 individual wait events. However, experienced DBA's find that they do tend to run across a very common set of wait events that occur most often on "slow" systems. There is a strong enough argument for extracting and reporting the wait times for some individual wait events that you consider to be the "most common" wait events.

The benefit is that if any one of these particular wait event times is very high, then we already have extracted it and reported it for analysis and can see it in the output. If all of these particular wait event times are low, then there was almost no extra cost involved in retrieving them at the same time as the other wait event times (there is no extra disk I/O, only some extra CPU to process the wait time data). It avoids the need to run another query afterwards to drill down into the wait event data, and if the extra wait data is irrelevant then we can just ignore it. And the mechanism is the same one as for the wait classes, using "decode" against the event name.

The top wait events that I am going to include are listed below. It's not a large list as I want to focus on the query, not the specific wait events. You can disagree with some of these, or want to add some others of your own. You can do this just by modifying the query I give below and changing the event names used in the "decode" functions.

• db file sequential read
• db file scattered read
• direct path read
• log file sync
• log file parallel write
• gc buffer busy
• gc cr block busy

As well as the total wait time for each event, we would also want to know the number of waits that occurred so we can calculate the average time per wait. This is important as it might not be the number of waits that is the problem but the average time per wait. We can achieve a "count" by doing a "sum" using one (1) when the wait event name matches, and zero (0) otherwise. This keeps it uniform with the wait time per event.

The only changes to the refactored sub-query given earlier are the addition of these extra data items to the "select" output list:

      , sum (decode (syswaitevents.event_name, 'db file sequential read', syswaitevents.time_waited_micro, 0)) db_file_sqrd_time
      , sum (decode (syswaitevents.event_name, 'db file sequential read', 1, 0)) db_file_sqrd_count
      , sum (decode (syswaitevents.event_name, 'db file scattered read',  syswaitevents.time_waited_micro, 0)) db_file_sctrd_time
      , sum (decode (syswaitevents.event_name, 'db file scattered read',  1, 0)) db_file_sctrd_count
      , sum (decode (syswaitevents.event_name, 'direct path read',        syswaitevents.time_waited_micro, 0)) direct_path_read_time
      , sum (decode (syswaitevents.event_name, 'direct path read',        1, 0)) direct_path_read_count
      , sum (decode (syswaitevents.event_name, 'log file sync',           syswaitevents.time_waited_micro, 0)) log_file_sync_time
      , sum (decode (syswaitevents.event_name, 'log file sync',           1, 0)) log_file_sync_count
      , sum (decode (syswaitevents.event_name, 'log file parallel write', syswaitevents.time_waited_micro, 0)) log_file_prl_wr_time
      , sum (decode (syswaitevents.event_name, 'log file parallel write', 1, 0)) log_file_prl_wr_count
      , sum (decode (syswaitevents.event_name, 'gc buffer busy',          syswaitevents.time_waited_micro, 0)) gc_buff_busy_time
      , sum (decode (syswaitevents.event_name, 'gc buffer busy',          1, 0)) gc_buff_busy_count
      , sum (decode (syswaitevents.event_name, 'gc cr block busy',        syswaitevents.time_waited_micro, 0)) gc_cr_blk_busy_time
      , sum (decode (syswaitevents.event_name, 'gc cr block busy',        1, 0)) gc_cr_blk_busy_count

Then we need to add these extra columns to the output of the main "select", remembering to divide times in microseconds by one million:

     , syswaits.db_file_sqrd_time     / 1000000 db_file_sqrd_time
     , syswaits.db_file_sctrd_time    / 1000000 db_file_sctrd_time
     , syswaits.direct_path_read_time / 1000000 direct_path_read_time
     , syswaits.log_file_sync_time    / 1000000 log_file_sync_time
     , syswaits.log_file_prl_wr_time  / 1000000 log_file_prl_wr_time
     , syswaits.gc_buff_busy_time     / 1000000 gc_buff_busy_time
     , syswaits.gc_cr_blk_busy_time   / 1000000 gc_cr_blk_busy_time
     , syswaits.db_file_sqrd_count     db_file_sqrd_count
     , syswaits.db_file_sctrd_count    db_file_sctrd_count
     , syswaits.direct_path_read_count direct_path_read_count
     , syswaits.log_file_sync_count    log_file_sync_count
     , syswaits.log_file_prl_wr_count  log_file_prl_wr_count
     , syswaits.gc_buff_busy_count     gc_buff_busy_count
     , syswaits.gc_cr_blk_busy_count   gc_cr_blk_busy_count

Note that I have chosen to keep the times together and the counts together, rather than alternate between them for each event in turn. This particular ordering makes it easier to copy an "average wait time" formula from one cell to another in a spreadsheet, as each referenced column shifts by one column in each case.

With these columns added, the output from my AWR summary report becomes:

SNAP                SNAP       DB SQL EXEC ALL WAIT  BG WAIT   COMMIT  CLUSTER CONCRNCY  NETWORK   SYS IO  USER IO  DBF SEQ DF SCTRD DRCT PTH  LOG FILE LG FL PR  GC BUFF GC CRBLK    DBF SEQ   DF SCTRD   DRCT PTH   LOG FILE   LG FL PR    GC BUFF   GC CRBLK
TIME            DURATION     TIME     TIME     TIME     TIME  WAIT TM  WAIT TM  WAIT TM  WAIT TM  WAIT TM  WAIT TM  RD TIME  RD TIME  RD TIME SYNC TIME  WR TIME BSY TIME BSY TIME     RD CNT     RD CNT     RD CNT   SYNC CNT     WR CNT    BSY CNT    BSY CNT
--------------- -------- -------- -------- -------- -------- -------- -------- -------- -------- -------- -------- -------- -------- -------- --------- -------- -------- -------- ---------- ---------- ---------- ---------- ---------- ---------- ----------
11/09/13 06:00     3,615    1,594    1,292      894      154      104       61        6      482       52      114       85        3       24       104       22        0       18     20,096        880     31,531     45,162     47,067         18      1,390
11/09/13 07:00     3,591    1,638    1,352      907      190       71       38        8      491       98      119       53        9       53        71       49        0        2     13,934      2,584     51,890     47,190     49,327         30        232
11/09/13 08:00     3,589    2,149    1,869    1,324      188       64       70        8      503       86      518      388       14       98        64       41        0        2    199,512      5,722     74,116     49,184     51,518         28        849
11/09/13 09:00     3,640    5,516    5,062    3,344      223       83      382       24      582       94    2,081    1,681       38      218        83       50      146        3    635,825     10,174    147,400     80,669     85,350     65,098      2,136 
11/09/13 10:00     3,558   11,193   10,150    6,625      326      264    1,040      146      670      161    4,007    2,980      227      710       264       87      106       34    744,366     90,168    415,035    129,443    136,572    116,076      8,471
11/09/13 11:00     3,630   16,981   15,578   10,260      486      371    1,294      116      865      255    7,116    5,804      368      495       371      144       14       18  1,346,338    162,856    274,090    191,730    201,510        834      4,778
11/09/13 12:00     3,609   15,954   14,349    9,516      497      508    1,456      143      876      231    5,887    4,979      185      579       508      125       70       68  1,230,115     92,290    317,980    186,878    197,001      3,207      8,931
11/09/13 13:00     3,602   10,800    9,651    6,013      383      278      774       81      747      181    3,665    3,191       87      323       278      102       18       21    954,932     32,045    200,258    173,877    184,167        661      9,443
11/09/13 14:00     3,562    8,532    7,562    4,359      319      203      488       55      698      158    2,566    2,364       25      149       203       92       22       12    553,064      6,607    133,380    159,407    169,369        388      6,391
11/09/13 15:00     3,601   11,486   10,210    6,721      402      374      899      111      751      189    4,102    3,485      157      304       374      109       42       50    814,112     79,733    214,011    172,358    181,824      1,944      7,554

As I said at the beginning this is a lot more columns of data than before. But the whole point is that we can now cut and paste this into a spreadsheet and do further analysis of the data to identify high values of one form or another. Now we not only have a break down of wait time by wait class, we also have the times and counts for the most common wait events.

Previously we saw that from 9am to 10am the major wait time was User I/O at 4,007 seconds out of 6,625 seconds for all waits. Now we can see that the one wait event of "db file sequential read" accounted for almost 3,000 seconds (2,980) out of the 4,000 for User I/O. We can also see that the next longest wait is probably "direct path read" at 710 seconds. So we now know which wait event contributed the most wait time, and how many times it occurred. And this lets us calculate the average "db file sequential read" for that period as being 0.004 seconds i.e. 4 milliseconds. Depending on your particular situation you may view this as being a high average time, or normal and acceptable. If the average wait time is acceptable then you would look at the number of such reads and try and find which SQL statements are causing them and tune those.

AWR Summary Reporting #3 - Waits

So far I've shown the skeleton of a query that lists out some key activity data values from all the data captured by AWR in its regular snapshots. So far we've only extracted a few time based data values:

• Duration - real clock time that occurred between the AWR 2 snapshots being reported on
• Database Time - time spent by the database being active
• SQL Execution Time - time spent by the database executing SQL statements

AWR captures a lot of other data in its snapshots and we can add more of these to our query to drill down further into what happened between each pair of snapshots. These other data sets include:

• Wait event data - individual wait events and wait time, and wait classes
• System statistics - as normally seen in V$SYSSTAT as cumulative counters
• SQL execution statistics for individual SQL statements

As before, I'll be adding these as separate sub-queries in the WITH clause so that they produce one row of data values per snapshot, and then joining to these named sub-queries in the main query and outputting the data values we want. This keeps the main query simpler, and pushes issues about grouping and summarising into the sub-query. It also lets us refer to the same sub-query multiple times if needed - which is the case for some of the data captured by AWR e.g. System Statistics are captured as sets of Name / Value pairs per snapshot.

For now lets add on wait event data telling us how long the system waited on different types of events. As we already have two different times for database activity (DB Time & SQL Execution Time), we would most like to know the total wait time within that database activity. This would let us calculate the actual time doing real SQL execution work, and see wait time as a percentage of total database time. The basic query for this extracts the wait times in microseconds from DBA_HIST_SYSTEM_EVENT, and would be:

, syswaits as 
(select sysevent.snap_id
      , sysevent.dbid
      , sum (sysevent.time_waited_micro - psysevent.time_waited_micro) all_wait_time
   from dba_hist_system_event sysevent, dba_hist_system_event psysevent
  where sysevent.snap_id = psysevent.snap_id + 1
    and sysevent.dbid = psysevent.dbid
    and sysevent.instance_number = psysevent.instance_number
    and sysevent.event_id = psysevent.event_id
    -- Ignore Idle wait events
    and sysevent.wait_class != 'Idle'
  group by sysevent.snap_id
         , sysevent.dbid
) -- syswaits

Note that I exclude "Idle" waits, which are waits unrelated to the execution of a SQL statement.

The next logical thing would be to break down the total wait time somehow into various major components, to show which type of waits occurred more often than the others. There are 3 major ways to break down wait events:

• Foreground versus background waits i.e. waits experienced directly by sessions for connected users, and waits experienced by permanent background server sessions
• By Wait Class - these group individual events into common classes such as Concurrency, User I/O, Commit, Network, Cluster.
• By individual wait event - unfortunately there are around 100 of these, and outputting these as individual columns in the query would be too cumbersome.

So the obvious thing to do is to split out foreground or background wait times (the other one can be calculated using the total wait time), and by wait class as there are only about 10 or so of these. Background waits are actually obtained from a different AWR snapshot table - DBA_HIST_BG_EVENT_SUMMARY. So the query for this would be:

, sysbgwait as 
-- One row per System Wait Event with change in value between snapshots
(select sysevent.snap_id
      , sysevent.dbid
      , sum (sysevent.time_waited_micro - psysevent.time_waited_micro) time_waited_micro
         from dba_hist_bg_event_summary sysevent, dba_hist_bg_event_summary psysevent
        where sysevent.snap_id = psysevent.snap_id + 1
          and sysevent.dbid = psysevent.dbid
          and sysevent.instance_number = psysevent.instance_number
          and sysevent.event_id = psysevent.event_id
          and sysevent.wait_class != 'Idle'
        group by sysevent.snap_id, sysevent.dbid
) -- sysbgwait

This gives the total background wait time in each snapshot for each database instance. The main query can then join to this as it does to the other sub-queries.

For the wait classes we now have two main choices for how to write such sub-queries:

• Have separate sub-queries for each class
• Collapse the sub-queries into just one sub-query using the "decode" function to sum values over different criteria

The trouble with the first approach is that each sub-query will probably be executed separately, meaning multiple reads of the same snapshot wait event data to produce multiple data sets, and then each sub-query data set will be joined together by Snapshot ID and Database ID. The second approach should be more efficient when executed - there is only one read of the AWR wait event data, and it is processed as it is read into one result set without any further joins between different wait event data subsets (the only joins are to the other AWR data sets in the main query).

The classes can be broken out using the Oracle "DECODE" function as an "IF" function to test the class name.

, syswaits as 
(select sysevent.snap_id
      , sysevent.dbid
      , sum (sysevent.time_waited_micro - psysevent.time_waited_micro) all_wait_time
      , sum (decode (sysevent.wait_class, 'Commit', (sysevent.time_waited_micro - psysevent.time_waited_micro), 0)) commit_time
      , sum (decode (sysevent.wait_class, 'Cluster', (sysevent.time_waited_micro - psysevent.time_waited_micro), 0)) cluster_time
      , sum (decode (sysevent.wait_class, 'Concurrency', (sysevent.time_waited_micro - psysevent.time_waited_micro), 0)) concurrency_time
      , sum (decode (sysevent.wait_class, 'Network', (sysevent.time_waited_micro - psysevent.time_waited_micro), 0)) network_time
      , sum (decode (sysevent.wait_class, 'System I/O', (sysevent.time_waited_micro - psysevent.time_waited_micro), 0)) system_io_time
      , sum (decode (sysevent.wait_class, 'User I/O', (sysevent.time_waited_micro - psysevent.time_waited_micro), 0)) user_io_time
   from dba_hist_system_event sysevent, dba_hist_system_event psysevent
  where sysevent.snap_id = psysevent.snap_id + 1
    and sysevent.dbid = psysevent.dbid
    and sysevent.instance_number = psysevent.instance_number
    and sysevent.event_id = psysevent.event_id
    -- Ignore Idle wait events
    and sysevent.wait_class != 'Idle'
  group by sysevent.snap_id
         , sysevent.dbid
) syswaits

The principle is that if the wait class name matches the target class name then the corresponding wait time is used in the sum, otherwise zero is used meaning that particular wait time is not included in the sum for that wait class.

Adding this to our existing query gives the following - note the divides by one million to convert microseconds to seconds:

with
snaps as 
...
, systimes as 
...
, sysbgwait as
...
, syswaits as
...
select to_char (snaps.end_snap_time, 'DD/MM/YY HH24:MI') snap_time
     , extract (second from snaps.snap_interval) 
       + (extract (minute from snaps.snap_interval) 
          + (extract (hour from snaps.snap_interval)
             + (extract (day from snaps.snap_interval) * 24)
             ) * 60
          ) * 60 snap_duration
     , dbtime.value / 1000000 db_time
     , sqlexectime.value / 1000000 sql_exec_time
     , syswaits.all_wait_time / 1000000 all_wait_time
     , sysbgwait.time_waited_micro / 1000000 bg_wait_time
     , syswaits.commit_time / 1000000 commit_time
     , syswaits.cluster_time / 1000000 cluster_time
     , syswaits.concurrency_time / 1000000 concurrency_time
     , syswaits.network_time / 1000000 network_time
     , syswaits.system_io_time / 1000000 system_io_time
     , syswaits.user_io_time / 1000000 user_io_time
  from snaps
     join (select * from systimes where stat_name = 'DB time') dbtime
       on snaps.snap_id = dbtime.snap_id and snaps.dbid = dbtime.dbid
     join (select * from systimes where stat_name = 'sql execute elapsed time') sqlexectime
       on snaps.snap_id = sqlexectime.snap_id and snaps.dbid = sqlexectime.dbid
     join syswaits
       on snaps.snap_id = syswaits.snap_id and snaps.dbid = syswaits.dbid
     join sysbgwait
       on snaps.snap_id = sysbgwait.snap_id and snaps.dbid = sysbgwait.dbid
 order by snaps.end_snap_time
/

And again, it would be good to define some nice column formats when running this in SQL*Plus:

col snap_time         format a15         heading 'SNAP|TIME'
col snap_duration     format 999,999     heading 'SNAP|DURATION'
col db_time           format 999,990     heading 'DB|TIME'
col sql_exec_time     format 999,990     heading 'SQL EXEC|TIME'

col all_wait_time     format 999,990     heading 'ALL WAIT|TIME'
col bg_wait_time      format 999,990     heading 'BG WAIT|TIME'
col commit_time       format 999,990     heading 'COMMIT|WAIT TM'
col cluster_time      format 999,990     heading 'CLUSTER|WAIT TM'
col concurrency_time  format 999,990     heading 'CONCURNCY|WAIT TM'
col network_time      format 999,990     heading 'NETWORK|WAIT TM'
col system_io_time    format 999,990     heading 'SYS IO|WAIT TM'
col user_io_time      format 999,990     heading 'USER IO|WAIT TM'

When run the output is something like this:

SNAP                SNAP       DB SQL EXEC ALL WAIT  BG WAIT   COMMIT  CLUSTER CONCURNCY  NETWORK   SYS IO  USER IO
TIME            DURATION     TIME     TIME     TIME     TIME  WAIT TM  WAIT TM   WAIT TM  WAIT TM  WAIT TM  WAIT TM
--------------- -------- -------- -------- -------- -------- -------- -------- --------- -------- -------- --------
11/09/13 06:00     3,615    1,594    1,292      894      154      104       61         6      482       52      114
11/09/13 07:00     3,591    1,638    1,352      907      190       71       38         8      491       98      119
11/09/13 08:00     3,589    2,149    1,869    1,324      188       64       70         8      503       86      518
11/09/13 09:00     3,640    5,516    5,062    3,344      223       83      382        24      582       94    2,081
11/09/13 10:00     3,558   11,193   10,150    6,625      326      264    1,040       146      670      161    4,007

As before, this particular database is relatively inactive before 9am, then becomes more active. Now we can see that the wait time is significant e.g. about 60% of Database Time is actually Wait Time in the hour up to 10am. And we can see that the largest component of this Wait Time is User I/O. We can also see that the next highest Wait Time component is Cluster wait time.

What next? We could either try and drill down into individual wait events, or maybe look at the SQL statements being executed and the waits they experience. More in future blog posts.

AWR Summary Reporting #2

Following on from my previous post on doing summary reports on the data captured in the AWR. Here is some example output from using that query, and a useful statistic you can derive from the output data it produces.

The previous query just gave us 3 time values:

• Duration - real clock time that occurred between the AWR 2 snapshots being reported on
• Database Time - time spent by the database being active
• SQL Execution Time - time spent by the database executing SQL statements

If you use the following WHERE clause within the SQL I gave before you get these data values that have been captured today:

where snaps.end_snap_time > trunc (sysdate)

And with suitable column formatting

col snap_duration format 999,990.9
col db_time       format 999,990.99
col sql_exec_time format 999,990.99

you get output like the following:

SNAP_TIME      SNAP_DURATION     DB_TIME SQL_EXEC_TIME
-------------- ------------- ----------- -------------
15/08/13 00:00       3,602.0    1,637.70      1,394.76
15/08/13 01:00       3,605.1    1,378.69      1,175.09
15/08/13 02:00       3,586.6    2,219.12      2,024.38
15/08/13 03:00       3,619.0    1,436.43      1,265.08
15/08/13 04:00       3,626.7    1,190.99      1,021.95
15/08/13 05:00       3,552.6    1,216.76      1,051.03
15/08/13 06:00       3,602.9    1,287.73      1,104.61
15/08/13 07:00       3,594.1    1,595.69      1,392.66
15/08/13 08:00       3,606.4    2,351.33      2,132.49
15/08/13 09:00       3,609.6    3,449.07      3,132.93
15/08/13 10:00       3,622.1    9,128.43      8,266.52
15/08/13 11:00       3,598.8   12,355.47     10,913.63

And as mentioned you can cut and paste this into a spreadsheet and derive other statistics from these measurements.

One obvious measurement is Average Active Sessions, which is a measure of how many sessions were active at the same time. An "active session" will be doing work and will be measured as an increase in "Database Time". So dividing "Database Time" by the elapsed time between the consecutive snapshots will give you the Average Active Sessions.

We can see that between 8 and 9am the AAS was just under 1 (0.96), while between 9 and 10am it had risen to 2.52, and between 10 and 11am it was 3.43. Depending on the number of CPUs in your system this may or may not indicate an overloaded system. This particular system has 8 CPUs, so it can easily handle under 4 concurrently active sessions and is not overloaded.

Next, I'll add on some more SQL sub-queries to the main query to pull out other data from the AWR, telling us about other things that happened on the system.

Summary Reporting on AWR Data 1

The addition of the Automatic Workload Repository (AWR) in Oracle 10g was a good thing, as its regular hourly snapshots collect and store a number of database wide activity statistics which allows historical reporting later on. However, the Oracle supplied standard AWR report (awrrpt) only provides detailed information on the activity that happened in one period of time between 2 snapshots. There is no summary report of activity across all of the snapshots in the AWR. Which means that to use the standard AWR report you first have to know which period of time is the important one you should be looking at. So how do you identify the "most active" time period?

The lack of any standard reports or analysis that works on the whole of this data set and summarises it seems to be something of a missed opportunity to me. And something that is vital when analysing historical activity and trying to identify hot spots. So I decided to write my own reports summarising activity between each snapshot over a number of snapshots i.e. over a number of days.

For each snapshot the report lists the change in value of the main activity statistics since the previous snapshot, all on one output line per snapshot, ordered by snapshot time. I can then use this output to determine the most active period (e.g. high SQL executions, high DB time) or the highest wait events (wait time) or something else. Generally I do this by loading the output into Excel (fixed width format data fields) and either glancing down some critical columns of data, or graphing them and looking for spikes. And within Excel I can also enter formulae and derive other statistics e.g. Average Active Sessions from DB Time and Elapsed Time.

Your mileage will vary with my report - you may not want some of the statistics I report, you may want some other ones, or you may want them formatted differently. But you can always edit the SQL and tweak it to your satisfaction. The main benefit is that you get all of the activity history captured in the AWR summarised into key measurements per snapshot. And this can be used to easily identify the busiest period, and also examine bottlenecks that give rise to high wait events.

I won't give all the raw SQL, as it is very long with multiple joins between many AWR tables. What I will do is build up the components of the SQL in stages, so you can build your own customised AWR query. I did create this particular SQL query myself, rather than simply copying someone else's, but I have seen the same concept used by others - for instance Karl Aaro, and it is interesting to see both how other people have pulled out this data (the SQL they use), and which statistics they deem most important and why.

Core Query - List of Snapshots

The core query is one that provides the list of snapshots, and the elapsed time of each one. I use the "WITH" sub-query clause of the "SELECT" query to keep each sub-query separate and make the final query simpler and easier to read.

with
snaps as 
(select csnaps.snap_id
      , csnaps.dbid
      , min (csnaps.end_interval_time) end_snap_time
      , min (csnaps.end_interval_time) - min (csnaps.begin_interval_time) snap_interval
   from dba_hist_snapshot csnaps
  group by csnaps.snap_id, csnaps.dbid
) -- snaps

This provides a list of snapshot identifiers, which are a foreign key that appears in all other AWR tables, and identifies each snapshot of activity data itself. It also provides some other key data items, which can be important when summarising the data:

• Database Identifier (dbid). This should be the same for all snapshots, but may not be under some circumstances. It is important to use in joins to other tables to ensure you are only getting activity data for the same database.
• When the snapshot period finished (end_interval_time)
• Snapshot duration (end time minus start time)

On a RAC system you will get separate snapshots of data for each instance, which means that there can be more than one end and start time per snapshot (one per instance). To get just one value for the start and end times I use the "min" aggregate function.

Database Time Model

This sub-query provides the set of Database Time Model data statistics per snapshot e.g. DB Time, sql execute elapsed time.

, systimes as 
-- One row per Database Time Model with change in value between snapshots
(select systime.snap_id
      , systime.dbid
      , systime.stat_name
      , sum (systime.value - psystime.value) value
         from dba_hist_sys_time_model systime, dba_hist_sys_time_model psystime
        where systime.snap_id = psystime.snap_id + 1
          and systime.dbid = psystime.dbid
          and systime.instance_number = psystime.instance_number
          and systime.stat_id = psystime.stat_id
-- Assume if stat_id the same so is the stat_name
        group by systime.snap_id, systime.dbid, systime.stat_name
) -- systimes

As before I group by the snapshot identifier, database identifier, and also statistic name. As the statistics values are cumulative, I am interested in the change in the value between two consecutive snapshots. So I join the Sys Time Model table to itself on the snapshot identifier being one more than the previous snapshot, and subtract the two data values (value column in this particular case) to get the change in value between the two snapshots. In case there is more than one data value per snapshot, which there will be on a RAC database, I also join by the instance number and add up the values together (sum aggregate function).

AWR Summary #1

Combining the two sub-queries together with suitable join conditions gives the following SQL to summarise database activity times between all snapshots:

with
snaps as 
...
, systimes as 
...
select to_char (snaps.end_snap_time, 'DD/MM/YY HH24:MI') snap_time
     , extract (second from snaps.snap_interval) 
       + (extract (minute from snaps.snap_interval) 
          + (extract (hour from snaps.snap_interval)
             + (extract (day from snaps.snap_interval) * 24)
             ) * 60
          ) * 60 snap_duration
     , dbtime.value / 1000000 db_time
     , sqlexectime.value / 1000000 sql_exec_time
  from snaps
     join (select * from systimes where stat_name = 'DB time') dbtime
       on snaps.snap_id = dbtime.snap_id and snaps.dbid = dbtime.dbid
     join (select * from systimes where stat_name = 'sql execute elapsed time') sqlexectime
       on snaps.snap_id = sqlexectime.snap_id and snaps.dbid = sqlexectime.dbid
 order by snaps.end_snap_time
/

Notes:

• The "snap_interval" is an INTERVAL data type, so to convert to just seconds I need to extract each time field component, multiply it up and add on to the other time components.
• The times in the Sys Time Model are in microseconds, so I divide by one million to get the value in seconds.
• The Sys Time Model data is stored as name / value pairs, so I need to query the same data set twice restricting to one named statistic each time. I do this in an inline view within the query.
• The joins between all data sets are on the Snapshot Identifier and the Database Identifier.
• From these data items you can derive other useful numbers e.g. Average Active Sessions is DB Time divided by Snapshot Duration.

This reports everything in the AWR, but you can restrict it to certain days by adding in a suitable WHERE clause. Here is one I use in SQL*Plus that refers to 2 numbers passed in as arguments when you invoke the script.

 where snaps.end_snap_time between 
       (trunc (sysdate) - &1) and (trunc (sysdate) - &1 + &2)

You can also format the columns nicely in SQL*Plus by pre-defining column formats:

col snap_duration format 999,990.9
col db_time       format 999,990.99
col sql_exec_time format 999,990.99

In a future post I'll show some other sub-queries against the AWR tables that can be added in to pull out SQL statement execution statistics, and wait events, and other statistics.

Mercurial for tracking script change history

On the one hand source code control can be a nightmare involving complicated tools and formal processes, but on the other hand the ability to track the history of changes to a file can be really useful. With complicated SQL queries and stored procedures, seeing what changed between each major version can be useful when debugging a change in behaviour or when application performance degrades. What is needed is something that is straightforward enough to use (not overcomplicated), does not get in the way of what you really want to do, helps you easily see what changed and when, and provides the right amount of functionality (nothing essential missing). If it fails on any of these then it is probably not worth using.

Having stumbled across Mercurial about 4 years ago when I needed something for a project I was working on, over time I have found it will do almost everything I need, and I've not looked back since. I use it for pretty much anything - most obviously Oracle SQL scripts, database build scripts, stored procedures, and other programming languages (I like Python which I've mentioned before). But it will work on any kind of text file.

Why Mercurial? What are the main things I like about it?

• Command line interface and various GUI options
  • Command line access makes direct use easy if you prefer that
  • GUI options include a web browser interface, TortoiseHg GUI front end, and integration with other tools e.g. Eclipse
• Truly tracks changes to files
  • It really records what changed between your saves (commits), not just a copy of the new file
  • This makes more advanced things really easy and almost trivial e.g. taking a change and applying it as a patch to another version
• Changes saved as "Change Sets" - groups of changes to files are saved together at the same time
  • This is logically what you want - all your changes saved together as one set
• Changes saved when you say - as frequently or infrequently as you want
• You always have a full copy of the source code tree locally
  • None of this stuff about needing to check out in advance files you will need to change
• Detects which files have changed or been added
  • Makes it really easy when saving changes - helps you avoid "forgetting" an important file
  • Also makes it easy to see if anyone else has changed any other files
• Its repository (history of changes) sits alongside your source code in a separate directory at the top level
  • Its metadata is kept separate from your source code files
    • There are no extra metadata files or sub-directories mixed in with your source code files
• Many advanced features too
  • Branching within repositories - different sets of changes from a common point in history
    • Useful for support versions of released versions, and bug fixes
  • Linked repositories - parent / child relationship between repositories
    • Another way of doing branches and separating released versions from in-development ones
    • Change Sets made to one repository can be pushed across to another repository e.g. bug fixes
  • Fully distributed - multiple copies of a repository can exist and be reconciled with each other
    • Developers can work on their own copy of the source code, then push changes back into group level repositories
  • Flexibility over repository hierarchies
    • Can be flat (master and one per developer) or very hierarchical (master, testing, project, sub-project, developer)

I'm probably making it sound more complicated than it is. I use it all the time in a very straightforward way because it is so easy, and it lets me see my change history if I ever need to. From my perspective here is what I do on any discrete project I work on.

• If there is any existing source code for the project get a copy of it locally
• Initialise the Mercurial repository ("hg init") and save the baseline
  • hg commit -m 'Baseline'
• Edit any files I need to edit, test, and repeat until I'm satisfied
• Save my changes locally in Mercurial
  • hg commit -m 'Description of what I did'
• If changes need to be propagated to another source code control tool, work out what files changed
  • TortoiseHg gives you a straightforward view of what files were changed in each commit
  • Or use the command line to see what changed in the last commit "hg log -v"
  • Or any previous commit (revision number) "hg log -v -r REV#"
• If using another source code control tool, synchronise with it when needed
  • Update my local copy of files from the other source code control tool with their latest version
  • Mercurial will detect what files have changed, if any
  • Save the changes in Mercurial with an appropriate message
    • hg commit -m 'Synced with master for latest changes by others'
• If the intended changes are tentative or need extensive testing, I first take a full copy of the source code tree (Mercurial repository)
  • hg clone existing-repo repo-copy-name
  • This keeps my new changes separate from the original ones, and avoids issues over needing to back out rejected changes later on
  • After testing if the changes are accepted I "push" them back to the parent repository it was cloned from
    • Otherwise I just delete the copy of the source code and abandon those changes
  • All changes made since the repository was cloned are pushed back to the parent
    • So the number of local saves I did during editing and testing does not matter - all my changes are propagated back
• Having multiple clones lets me work on different projects at the same time, without mixing up their changes in the same source code tree

As I said before, this lets me easily keep a local repository tracking all changes made to source code files, so I can see who changed what and when. It also enables me to keep multiple copies of a master source code tree and test out different changes independently of each other, and only push back changes when thoroughly tested and accepted by everyone else.

Your mileage will vary, but I find Mercurial easy enough to use, and it provides the right level of tracking of source code changes that I want.

My Top Technical Tools

I find that during my technical work on Oracle and Performance Tuning there are a few key pieces of software that I keep coming back to again and again. They are not directly related to databases, and are really more like technical tools that help me do my work better. Each does a unique thing, and does it so well that they have become standard tools I use all of the time one way or another.

So my top technical utilities that I could not do without, in no particular order, are:

• TiddlyWiki - a great personal Wiki for keeping together all the bits of useful information I come across
• Mercurial - source code control, great for tracking the history of all my SQL scripts
• VirtualBox - virtualised environments for testing multiple Linux and Oracle versions
• Trello - an online list tool, great for do lists and following mini projects

I'm not trying to say that each of these is the best possible for each thing. I'm saying that they are so easy and straightforward to use that I use them again and again. And their feature set is great in each case - just what I want, no more, no less. Each of these tools has advantages that makes it more useful than other options out there or just not using anything at all.

TiddlyWiki is a self contained Wiki in a single HTML file, with a built in editing capability. So you can carry around your own Wiki on a memory stick as a single HTML file, and keep adding to it any time you want to. As ever it uses a bit of meta-syntax to embed formatting and hyperlinks. But that is it - no complicated set up or configuration, or other dependencies. Its portable - I use Firefox as my browser, but on Windows or Linux or anything else.

Mercurial tracks changes to text files i.e. source code versioning. Great for tracking changes to all of my numerous SQL scripts over time. Again, no complicated set up, though you do need to install it first (either build from scratch or as an installable package if available for your operating system). It keeps a record of what you changed in each file whenever you do a commit (an update to the history in its repository). It is dead easy to see the history of changes to any given file (often difficult for some tools) - specifically what changed and when. I've used it for all kinds of "source code files" on projects and been able to debug bad changes by working out when certain changes were made and by whom. You might never need to go "back in time" to see old versions of scripts, but when you do need to it is invaluable. And for just a little disk overhead of keeping the change history.

I'm sure many of you know about VirtualBox for creating virtual machines. I can easily create a new virtual machine, install what variant of Linux I want, and do any testing I want - all in isolation from other things. Really useful for creating sandpit test environments, and throwing together specific combinations of software without needing a dedicated system.

Trello is my latest discovery from about 2 years ago. I've always wanted a "good enough" do list tool, but nothing too complicated or over the top - not full blown project management. I want to add new items easily, add new lists, move things between lists, order them as I want to within a list, and mix lists and items together nesting them in each other. Trello lets me do this. Although web based and requiring registration, it has a great GUI with drag and drop of items - within lists and between lists. Again, they have made it really easy to use. Click for a new item, type it in, and save. Editing is just a case of clicking twice (once to open, then edit). Trello kind of has 4 levels of hierarchy within it, so you can work out which combination of levels works best for you. There are boards (separate sets of lists), lists within a board, items within a list, and items can also have a checklist within them which is useful. So you either have one board with multiple lists and items, or multiple boards (one per project?) with lists of sub-projects and task level items. Or mix it another way. I like the checklists because they only appear when you open the item (keeping the main display less cluttered), and they work well for task lists as you tick them off as complete.