09 March 2016Customers

Visualising Oracle Performance Data with the Elastic Stack

Introduction

One of the great things about the Oracle database is the level of diagnostics and performance data that is available from it. Used in conjunction with good instrumentation from the applications generating the workload on the database, it’s a brilliant way – arguably, the only way – to accurately and efficiently get to the bottom of any performance problems that arise. By analysing what the database is doing at a point in time we can understand more about the load that it is under, and by looking at how a given session executes we can identify optimisation opportunities for it.

The data is available natively through some of the V$ system views, and exposed through Enterprise Manager, and tools such as SQL Developer. What I’m going to show in this article is how you can make use of the open-source Elastic Stack – comprising Elasticsearch, Logstash, and Kibana – to extract this data and visualize it as an alternative to the aforementioned options.

Why the Elastic Stack?

Because Kibana is a great data visualization and exploration tool. Because Elasticsearch is a great datastore that is dead easy to work with, and because Logstash makes getting data from a ridiculously large and varied number of sources an absolute doddle. It’s a stack I frequently use for monitoring and diagnosing applications including OBIEE, and including Oracle performance data in that analysis was an obvious thing to do.

Licensing

Elasticsearch, Logstash, and Kibana are all open-source tools that are free to use. You can pay for a subscription that gives you direct access to product support, as well as additional tools including for monitoring, security and alerting.

The Oracle Diagnostics Pack is required if you’re using functionality in Oracle including (but not limited to) Active Session History (ASH) – if in doubt, speak to your Oracle Account Manager.

Versions

This article was written using Elasticsearch 2.2, Logstash 2.2, Kibana 4.4, pulling data from Oracle 12c (12.1.0.1.0). I used the excellent Swingbench to generate load against the database.

Overview

The Elastic Stack gives you great flexibility to analyze exactly the data that you need, in exactly the way that you want to. In this article I’m going to show how to get Active Session History (ASH) data streamed into Elasticsearch. You might want to then enrich it further with log data from your applications, or OS metrics from the servers – or anything else that might be useful for a full-stack view of your application’s performance.

Using Logstash’s JDBC input, we pull data from the Oracle V$ACTIVE_SESSION_HISTORY table, loading the data directly into Elasticsearch. From there we can analyze it with Kibana. It really is as simple as that.

Setup

Choose your monitoring server. Elasticsearch and Logstash both run under the Java VM so are eminently portable across OSs. Kibana ships with binaries for Windows, Mac, and Linux. In this example, I’m running them on a Linux server.
Download the binaries:
You’ll also need the Oracle JDBC driver which you should be able to get from here (or via a download link at the parent page here). Don’t forget a current JDK too, if you don’t already have one.
Unpack the binaries and JDBC driver somewhere appropriate. In this example I use /opt.

Optionally, install one of the monitoring tools available for Elasticsearch.

My preference is for Marvel:

/opt/elasticsearch-2.2.0/bin/plugin install license  
/opt/elasticsearch-2.2.0/bin/plugin install marvel-agent  
/opt/kibana-4.4.0-linux-x64/bin/kibana plugin --install elasticsearch/marvel/latest

You can also use the kopf monitoring by running the following:

/opt/elasticsearch-2.2.0/bin/plugin install lmenezes/elasticsearch-kopf

Start Elasticsearch

/opt/elasticsearch-2.2.0/bin/elasticsearch

[2016-02-03 22:00:46,258][WARN ][bootstrap                ] unable to install syscall filter: seccomp unavailable: requires kernel 3.5+ with CONFIG_SECCOMP and CONFIG_SECCOMP_FILTER compiled in
[2016-02-03 22:00:46,644][INFO ][node                     ] [finbarr.saunders] version[2.2.0], pid[27659], build[8ff36d1/2016-01-27T13:32:39Z]
[2016-02-03 22:00:46,644][INFO ][node                     ] [finbarr.saunders] initializing ...
[2016-02-03 22:00:47,722][INFO ][plugins                  ] [finbarr.saunders] modules [lang-expression, lang-groovy], plugins [kopf], sites [kopf]
[2016-02-03 22:00:47,774][INFO ][env                      ] [finbarr.saunders] using [1] data paths, mounts [[/ (/dev/sda3)]], net usable_space [102.5gb], net total_space [190.7gb], spins? [possibly], types [ext4]
[2016-02-03 22:00:47,774][INFO ][env                      ] [finbarr.saunders] heap size [990.7mb], compressed ordinary object pointers [true]
[2016-02-03 22:00:53,772][INFO ][node                     ] [finbarr.saunders] initialized
[2016-02-03 22:00:53,772][INFO ][node                     ] [finbarr.saunders] starting ...
[2016-02-03 22:00:54,375][INFO ][transport                ] [finbarr.saunders] publish_address {127.0.0.1:9300}, bound_addresses {[::1]:9300}, {127.0.0.1:9300}
[2016-02-03 22:00:54,451][INFO ][discovery                ] [finbarr.saunders] elasticsearch/d27mNaltQXOFCgLqPuHk6Q
[2016-02-03 22:00:57,671][INFO ][cluster.service          ] [finbarr.saunders] new_master {finbarr.saunders}{d27mNaltQXOFCgLqPuHk6Q}{127.0.0.1}{127.0.0.1:9300}, reason: zen-disco-join(elected_as_master, [0] joins received)
[2016-02-03 22:00:57,926][INFO ][http                     ] [finbarr.saunders] publish_address {127.0.0.1:9200}, bound_addresses {[::1]:9200}, {127.0.0.1:9200}
[2016-02-03 22:00:57,966][INFO ][node                     ] [finbarr.saunders] started

screen

http://localhost:9200/_plugin/kopf/#!/cluster

Start Kibana:

/opt/kibana-4.4.0-linux-x64/bin/kibana/

http://localhost:5601/

Getting the Data into Elasticsearch

So far, so easy. Download and run a handful of binaries. But, we’ve not got any data yet. Enter Logstash. Logstash enables you to pull in data from one or many types of source, filter and enrich it, and then output it to Elasticsearch and many other destinations.

Here we’re using the Logstash JDBC input plugin. Note that this is relatively new (in the open-source sense) and previously was often done as a “River” – something now deprecated in Elasticsearch but I mention it here as you may still find articles through Google that reference it.

To use Logstash we need to build a configuration file. We’ll build this up step by step to make sure it’s all working along the way.

First Steps with Logstash JDBC Input

All Logstash configuration files have the same simple structure : input, filter, output. And of those, filter is optional. Here’s our starter for ten, that’ll act as a smoke-test for the Logstash-JDBC-Oracle connectivity:

input {
    jdbc {
        jdbc_validate_connection => true
        jdbc_connection_string => "jdbc:oracle:thin:@oradb:1521/orcl"
        jdbc_user => "system"
        jdbc_password => "Admin123"
        jdbc_driver_library => "/opt/ojdbc7.jar"
        jdbc_driver_class => "Java::oracle.jdbc.driver.OracleDriver"
        statement => "SELECT sysdate from dual"
       }
}
output   {
    stdout { codec => rubydebug }
}

The parameters in the input JDBC stanza are all pretty obvious – connection string, credentials, path to JDBC driver that you’ve installed, and the SQL to run.

For the moment we’re setting the output as simply back to the console, using some formatting provided by a codec (you don’t need to worry about this detail here – it just makes things easier to read).
Save this local to the server where you’re running Logstash (here I’ve saved it to ~/logstash-ora-01.conf), and then execute it :

/opt/logstash-2.2.0/bin/logstash -f ~/logstash-ora-01.conf

After a few seconds of Logstash firing up, you should see the output including the SYSDATE that it’s pulled through from Oracle

Settings: Default filter workers: 2
Logstash startup completed
{
       "sysdate" => "2016-01-30T22:19:30.000Z",
      "@version" => "1",
    "@timestamp" => "2016-01-30T22:19:30.112Z"
}
Logstash shutdown completed

Note that you’ve also got two internal Logstash fields in there: @version and @timestamp.

Polling Oracle

As you saw above, when we ran Logstash it ran the query once and then finished. We’re going to want to be polling the data out of Oracle on a continual basis in order to stream it into Elasticsearch. Let’s see how we can do that here.

As the documentation for the Logstash JDBC input plugin shows, a schedule can be specified in the parameters. The syntax matches that of cron. Our Logstash configuration file now looks like this, and will poll Oracle every two minutes:

input {
    jdbc {
        jdbc_validate_connection => true
        jdbc_connection_string => "jdbc:oracle:thin:@oradb:1521/orcl"
        jdbc_user => "system"
        jdbc_password => "Admin123"
        jdbc_driver_library => "/opt/ojdbc7.jar"
        jdbc_driver_class => "Java::oracle.jdbc.driver.OracleDriver"
        statement => "SELECT sysdate from dual"
        schedule => "*/2 * * * *"
       }
}
output {
    stdout { codec => rubydebug }
}

When we run it (and wait patiently!) we’ll see that every two minutes it’s pulling new data from Oracle:

Settings: Default filter workers: 2
Logstash startup completed
{
       "sysdate" => "2016-01-30T22:26:00.000Z",
      "@version" => "1",
    "@timestamp" => "2016-01-30T22:26:00.513Z"
}
{
       "sysdate" => "2016-01-30T22:28:00.000Z",
      "@version" => "1",
    "@timestamp" => "2016-01-30T22:28:00.062Z"
}

Now that Logstash is running on a stream of input data we need to explicitly kill it to get it to stop – Ctrl-C will do the job here.

^CSIGINT received. Shutting down the pipeline. {:level=>:warn}
Logstash shutdown completed

Oracle to Logstash to Elasticsearch

We’re getting closer now to the final configuration that we need. Let’s see how Logstash can be configured to send the data we’ve been pulling from Oracle into Elasticsearch, instead of just the console on stdout. It’s really difficult, I’m warning you now. (for my friends across the pond - that was sarcasm. Sending data to Elasticsearch is ridiculously easy!)

We’ll use the same input stanza, but with one little extra line in the output:

input {
    jdbc {
        jdbc_validate_connection => true
        jdbc_connection_string => "jdbc:oracle:thin:@oradb:1521/orcl"
        jdbc_user => "system"
        jdbc_password => "Admin123"
        jdbc_driver_library => "/opt/ojdbc7.jar"
        jdbc_driver_class => "Java::oracle.jdbc.driver.OracleDriver"
        statement => "SELECT sysdate from dual"
        schedule => "*/2 * * * *"
       }
}
output {
    stdout { codec => rubydebug }
    elasticsearch {}
}

Blink and you’d miss it, right? That one little elasticsearch {} is all that it takes to send data to Elasticsearch, as well as still sending it to stdout. The Elasticsearch output plugin supports lots of parameters, but if you’re running a single Logstash instance locally to a single Elasticsearch node, that’s really all you need.

If you now look in kopf you’ll see that an “index” called logstash- followed by the current date has appeared. The number of “documents” should match however many entries you’ve got on the console – each “document” is one record sent from Logstash to Elasticsearch. In RDBMS terms a document is roughly a row, and an index roughly a table.

You’ll also see in kopf that the top bar has turned from Green to Yellow, indicating the health of Elasticsearch. It’s gone Yellow as a warning, because you’re now storing data (which you weren’t before, when it was green) and you’ve only got a single node so no redundant copy of it for resilience. Elasticsearch, as the Elastic part of the name implies, scales horizontally by design and doing – so is a doddle. Provisioning extra nodes in the cluster is pretty much a case of just installing the binaries and updating the configuration to use the same cluster name – as soon as you fire them up Elasticsearch will automagically rebalance the data so that there are redundant copies – at which point the cluster health goes back to Green. Phew!

Did Someone Say Oracle Performance Data?

So far we’ve just been proving out the connectivity. Now let’s actually, finally, start pulling in some of the good stuff. Oracle’s V$ACTIVE_SESSION_HISTORY table holds a snapshot every second of what has been running on the database at that point in time. ASH, as it’s known, is one of the best ways to analyze the queries that have been running and what the database was doing whilst running them.

We’ll use the SAMPLE_TIME column on V$ACTIVE_SESSION_HISTORY as our predicate, otherwise we’ll pull back the whole contents of the table each time. The JDBC plugin can store on disk when it last ran, and it makes this available as a run-time variable to pass into the SQL. The SQL statement looks like this:

statement => "SELECT * FROM V$ACTIVE_SESSION_HISTORY WHERE SAMPLE_TIME > :sql_last_value"

Note that between Logstash 2.1 and 2.2 the name of this variable changed (along with some of the associated plugin parameters), from sql_last_start to sql_last_value.

Now we’re going to introduce a new stanza to the configuration: a filter. Logstash filters are basically pipeline processing functions – they might enrich the data, conditionally drop it, manipulate it, and so on. Here we’re just doing a straightforward field assignment, setting the date of the event (the @timestamp field that you can see in the sample output above) to that of the SAMPLE_TIME in the ASH data, rather than the current time of processing. By default Logstash will record each event that it processes (so in our case, a row of ASH data) as having occurred at the current time. If we’re streaming data from a log file, that’s probably true, but when we’re polling data (or back-populating historical data) it is important to assign the actual time to it. You’ll know if you’ve not done it when all your historical data shows up in Elasticsearch and Kibana with today’s date…

Note that whilst SAMPLE_TIME is a timestamp field, it can’t be directly assigned – we have to cast it to string first and then pattern match it:

mutate { convert => [ "sample_time" , "string" ]}  
date { match => ["sample_time", "ISO8601"]}

If you don’t cast it first, you’ll get the error cannot convert instance of class org.jruby.RubyObject to class java.lang.String. Thanks to javadifateme on github for this workaround. Watch out also that field names are case sensitive.

The completed configuration looks like this. Note that the stdout is commented out because there’s going to be a lot of data flowing and dumping it to the console slows things down somewhat. For debugging though, it’s useful to leave in.

input {
    jdbc {
        jdbc_validate_connection => true
        jdbc_connection_string => "jdbc:oracle:thin:@oradb:1521/orcl"
        jdbc_user => "system"
        jdbc_password => "Admin123"
        jdbc_driver_library => "/opt/ojdbc7.jar"
        jdbc_driver_class => "Java::oracle.jdbc.driver.OracleDriver"
        statement => "SELECT * FROM V$ACTIVE_SESSION_HISTORY WHERE SAMPLE_TIME > :sql_last_value"
        last_run_metadata_path => "/tmp/logstash-oradb.lastrun"
        record_last_run => true
        schedule => "*/2 * * * *"
       }
}
filter {
    # Set the timestamp to that of the ASH sample, not current time.
    mutate { convert => [ "sample_time" , "string" ]}
    date { match => ["sample_time", "ISO8601"]}
}
output {
    #stdout { codec => rubydebug }
    elasticsearch {}
}

The first time that you run this, it’s going to take a while, because the “last_run” value doesn’t yet exist (since we’ve never run it) and defaults to 1/1/1970. If you don’t want a full dump of ASH loaded, you could probably write a crafty CASE clause into the SQL to cater for this, or pre-create the lastrun metadata file on disk – it looks like this:

--- 2016-02-02 23:02:06.470000000 Z

Data Cleansing

When you run Logstash you may well get a screenful of errors like this:

Failed action.  {:status=>400, :action=>["index", {:_id=>nil, :_index=>"logstash-2016.02.02", :_type=>"logs", :_routing=>nil}, #<LogStash::Event:0x566d7547 @metadata_accessors=#<LogStash::Util::Accessors:0x95620e @store={}, @lut={}>, @cancelled=false, @data={"sample_id"=>#<BigDecimal:3c4cfaaa,'0.17901126E8',8(12)>, "sample_time"=>"2016-02-02T18:37:00.680Z",
[...]

and on Elasticsearch’s console too:

[2016-02-02 23:38:15,716][DEBUG][action.bulk              ] [Ariel] [logstash-2016.01.30][3] failed to execute bulk item (index) index
[...]
MapperParsingException[failed to parse [force_matching_signature]]; nested: JsonParseException[Numeric value (12852529615260526791) out of range of long (-9223372036854775808 - 9223372036854775807)
 at [Source: org.elasticsearch.common.io.stream.InputStreamStreamInput@5795fe7d; line: 1, column: 334]];
        at org.elasticsearch.index.mapper.FieldMapper.parse(FieldMapper.java:339)
        at org.elasticsearch.index.mapper.DocumentParser.parseObjectOrField(DocumentParser.java:314)

What’s happening here is that Logstash is sending data over to Elasticsearch that it’s not happy with in the data type that Logstash is claiming, hence Numeric value out of range. Looking closely at the Elasticsearch error we can see the field name that it’s not happy with:

failed to parse [force_matching_signature] [...]

and since we’re not interested in storing it, we’ll add another filter clause to just chuck it away:

# Drop "force_matching_signature" because its value sometimes blows the limits of the long data type  
mutate { remove_field => [ "force_matching_signature" ] }

Thanks to a recent change in Lucene (on which Elasticsearch is built), it is likely that in the future Elasticsearch will have more comprehensive support for large data types, as describe on this blog here. For here-and-now, I guess if it was a field that we wanted to retain it could be cast to a string for storage (or on the fetch from Oracle). I found that p3 also trips up on the same, so dropped it too. This does give me opportunity to mention a great feature of Elasticsearch – schemas (“mappings”) can evolve as needed, and if we want to start sending greater or fewer columns from Logstash to Elasticsearch we do just that, and Elasticsearch won’t bat an eyelid. In general, the SELECT * [...] is a bit of a lazy way to pull data out; much neater would be to build up a properly specified list of columns that we want and only the ones that we want.

So What Have We Got Now?

Having set Logstash running loading ASH data into Elasticsearch, you should see the volume of data in increasing as shown by kopf:

Each row from ASH is one “document” in Elasticsearch, and Logstash will by default partition data in Elasticsearch by date. In the above screenshot there are two days worth of data, and so two indicies (“logstash–2016.01.30” and “logstash–2016.02.02”). The date partitioning is another reason the timestamp field that we set in the filter clause above is important. Even though as we’ll see shortly Kibana can work with any timestamp field, we want to make sure that Elasticsearch is using the appropriate partitioning key: event timestamp.

Analytics on ASH - Enter Kibana

So far we’ve collected the ASH data from Oracle with Logstash, and stored it in Elasticsearch. Let’s see now how we can do some cool visualizations and analytics on it, using the third part of the Elastic Stack: Kibana.

Setting up Kibana

The first time you use Kibana (or add a new set of data to it in different indicies) you need to tell it what the index, or indicies pattern, is. Here we benefit from the tight integration within the Elastic Stack because Logstash by default writes to a partitioned index called logstash-[...], and Kibana by default reads data from an index called the same.

Launch Kibana in your favourite web browser by going to http://localhost:5601 (change localhost for the server on which you’re running Kibana), and you should see the Configure an index pattern screen as seen above. Leave the Index name as logstash-, and in the Time-field name list, pick @timestamp (remember that in the Logstash configuration we’ve already mapped this directly to sample_time):

Click Create, and Kibana will then list out all of the fields that it can find in the Elasticsearch index:

From here we’re going to explore the functionality that Kibana offers. It’s split up into three main areas: Discover, Visualize, and Dashboard. Dashboards are a compendium of one or more visualizations and searches (built with Discover), so really it’s only two that we need to learn!

Discover

This gives you access to the raw ‘documents’, viewing all the field values, and searching and filtering. The bar chart at the top of the page shows a count by time period of documents. The longer the time window shown, the greater the time period per bar.

By default just the timestamp of an event and the whole document (_source) are shown, which is of limited use if we’ve got lots of fields of useful data. By hovering over a field on the left you can opt to add or remove it from the columns in the table shown:

You can do neat things like see a summary of the proportion of occurrences of each value within a field (based on a sample):

and from there opt to show only those values, or to exclude them:

If you click on the toggle arrow next to a particular document the full contents is displayed, which can be a useful way to examine given record. From here you might identify fields that may be useful for data discovery and you therefore want to display as a column in the table, as well as data values that you want to specifically show-only, or exclude, from the table by adding a filter.

To save the view of the records (in terms of fields/columns shown, and filters applied), click the Save Search icon in the top right of the screen.

Visualize

Let’s head on over to Visualize now, where we can build useful aggregations on top of the data to help with our analysis of it.

We’ll start with an Area Chart:

Under buckets click X-Axis and set the Aggregation to Date Histogram. You can specify a time interval if you want, or leave it as Auto. Click the Apply button (the big green triangle).

You should see something similar to the bar chart in the Discover page that we saw previously. It’s a count of the number of documents, per time period. So here we’re seeing the number of active sessions on the database, summarised up per time period.

Let’s add a dimension to the data, and look at the SESSION_STATE within these sessions. To do this click on Add sub-buckets, Split Area, and set the Sub-Aggregation to Terms. Click the Field dropdown and set it to session_state.raw (note the raw suffix) and hit the apply button again.

OK, this is starting to look interesting. How about a third dimension - MODULE. This is one of those ones that any good application developer should be setting in order to improve the instrumentation and therefore diagnostics for their application. Read more about why this is so important in Cary Millsap’s slidedeck here. Anyway, here it is thrown into our Kibana visualization of ASH data:

To build this, I added a further sub-bucket, using the Split Chart option, and a Term aggregation on the module.raw field.

Now save the visualization (top right of the screen), because we’re going to use it shortly in a Dashboard.

Wondering why I’m using this .raw fields? These are to do with the powerful full text search that Elasticsearch (it’s even in the name, right) is so good at. By default Elasticsearch will “analyze” string fields and when you opt to aggregate against them do so against the terms it finds within them. So “Update Customer” might become two separate aggregations “Update” and “Customer”. This is useful in lots of cases, but not here. On its own “Update” and “Customer” are complete nonsense. Hence, use the .raw version of the fields, which under the covers are stored as “Not analyzed”. This is all done automagically for you in the default Logstash/Elasticsearch configuration, but you’ll want to look into index templates if you go start to go off-road with this.

Once you’ve got the hang of the Kibana interface you’ll find it a doddle to start properly slicing & dicing data to suit what you’re looking for. Here’s another example of a visualization I put together, and it’s so easy to do it only took a couple of minutes:

I’ve always scorned pie charts, but I think this one of ASH data is genuinely an appropriate use of the visualization. It shows what the user’s doing (module/action), and what the database is doing (session_state/wait_class/event). Perhaps as a standalone analytical visualization it still falls foul of the problem of pie charts (the human eye has difficulty perceiving the relative proportions of an area in a circle), but as we’ll see in a moment, visualizations can be interactive filters, and combined with the tooltips, I think this pie gets to stay…

Dashboards

Standalone ‘Discover’ and ‘Visualize’ explorations can sometimes be enough in themselves to answer the questions you have for the data, but typically you’ll want to pull several of them together. You might want a “dashboard” in the monitoring sense, or maybe just a way to show the detail rows of data for a given visualization.

From the Dashboard tab click the + icon in the top right of the page. From here you’ve got two tabs enabling you to select which visualizations and searches (from the Discover page) you want to include:

When you add them in they’ll first show up as small boxes which may well be too small to show the intended contents. Simply hover over the bottom-right corner of any of the boxes to resize (notice how the rest of the boxes rearrange themselves to make space – neat!). In no time at all, you can put together something like this:

And now the really neat bit – as I mentioned briefly before, the dashboard is interactive. You can hover over elements to see details about that data:

What’s more? You can click on any element such as a bar chart or pie chart segment to apply a filter for that segment of data. Here we can show all ASH records related to the identified module, action, and wait state:

Note the filters at the top of the screen - you can toggle these to change the view on the data. For example, to show all ASH records for the given module and action but regardless of state etc:

All the visualizations and data tables on the page show data as specified by the filters. This is a very intuitive, powerful, and flexible way for analysing your data!

Conclusion

The Elastic Stack is a fantastic way to quickly ingest data, store it, and analyze it. It’s so simple to install and get started with, and all of this can be done from a simple install on a laptop, or scaled up onto proper servers for production use with clustering for both resilience and performance.

You can see in some of my other blog posts examples of Elastic Stack in action for both systems monitoring and analytics, including against data in Hadoop. There’s also slides of my talk “Data Discovery and Systems Diagnostics with the Elastic Stack”, and a video of me presenting it at Yorkshire Database (YoDB) user group in 2015.

Robin Moffatt is Head of R&D (Europe) at Rittman Mead, and an Oracle ACE. He specialises in OBIEE and Linux as well as ODI, and more recently delving into the worlds of Hadoop and Elasticsearch. His particular interests are systems architecture, administration, and performance testing and optimisation. He blogs at http://ritt.md/rmoff and http://rmoff.net/ and can be found tweeting grumpy geek thoughts as @rmoff.

The Search AI Company

Generative AI

Search

Security

Observability

By solution

Industries