Unleashing Envers

Why Audit Logging?

Audit logging in the database may be one of those things that you have to experience to appreciate. Some of our clients have audit logging set up and others do not. When you’ve never experienced it it might not seem like a big deal. After you have it in place though and start to use it you wonder how you could ever live without it. By audit logging I mean having a snapshot in the database made every time a record is added, modified, or removed, along with when the change happened and (ideally) who made the change and why. The changes are typically stored in additional database tables, one for each regular table in the database. Each logging table records a snapshot of each record in the table it monitors, every time it changes.

• Troubleshooting/debugging: I can’t tell you how many times I’ve used audit logging to troubleshoot a bug report. Why is this product’s price suddenly $5 less than it used to be? Well user X lowered on April 22 last year at 9am. When did we change this discount from 20% off to 25% off? User Y did that, exacly 9 months and 21 days ago. So many answers to so many questions are right there in the logging tables.
• Usage metrics: It can be incredibly valuable to understand how an application is being used. Regular application logs can tell you this, but only to a point. Audit logs tell you not only what was done but what the results were. For example, SoftSlate administrators have the ability to manipulate orders after they are placed by customers, including adding items (say, if a customer service rep is upselling an item on the phone to the customer). You might need to know how often these tools are used and what the impact of the changes is. You can look through the Request Log to find out how many times a request was made to say, add an item. By querying the audit logs though, you can also know which items were most commonly added, what the financial impact was, and which CSRs were responsible for the upsells. Again, there is a fantastic depth to the information at hand in the audit logs. In this case for example, you could calculate commissions for your reps quite easily to encourage them to do more upselling.
• Compliance: Anyone’s who’s had the pleasure (not?) to go through SOX auditing will appreciate how invaluable audit logs can be. SOX is concerned with having a firm handle on financial information. For an ecommerce application, it might require some of the following:
  • A report on changes to an order (e.g. before and after values, who changed it, when it was changed, and why it was changed, etc.). Items added and removed, shipping methods changed, and discounts added or removed.
  • A report showing all pricing or discount changes for a specific period, including product price changes, and discounts created or modified.
  • A report showing when administrative users were activated or deactivated, and when their permissions or roles changed.

  The above is just a small sampling of the kinds of reports you might need to come up with. With audit logging in place, each of these reports becomes a matter a constructing an SQL query. Really, in most cases, one query and you’re done. Without audit logging in place, well, I think you’d have to make code changes in the application to record exactly what you need to record – for each requirement. It could keep someone busy for a long time.

Why Envers?

I have only one other technical approach to compare Envers to in my experience: database triggers that write to logging tables on every insert, update, and delete. We implemented this for clients in MySQL and it worked quite well for us for quite some time. If you want to see an example, here is the rough idea (although we implemented it differently).

People frown on database triggers, but I think you can make a decent argument for them in this particular case. The triggers aren’t implementing any business logic. They are very low-level and dumb: they just record the fact that you’ve changed this, that, or the other thing. And one huge advantage is that you can be sure the trigger will catch everything, including bulk statements. As far as I can tell Envers cannot record changes made to the database when using a bulk insert, update, or delete statement, where more than one entity is affected. Depending on the circumstance, this issue could be very important to you. Another advantage of database triggers over Envers is the fact that of course Envers doesn’t track changes made outside the context of Hibernate. Any changes made directly in the database, or by some other application, won’t be tracked. If this situation applies to you, you might want to consider triggers.

You have to hand it to Envers that all the random issues aside, it is easy to implement. Just add the .jar file to your project, create the logging tables, and it will start tracking. For most purposes the annotations to tell it which properties to audit and which not to, and other configurations, are useful. The ease of implementation, the fact that it’s part of your application itself, and the configurability, are its big pluses I feel.

All that said, here are some of the issues we encountered. (By the way, Envers is available starting with version 3.3.5 of SoftSlate Commerce.)

Envers Is Turned On By Default, But We Wanted It Turned Off By Default

If you add the Envers jar file to your application, it will automatically be enabled. What this means is that it will register event listeners with Hibernate. Event listeners respond to every insert, update, and delete made against entities (but not bulk inserts, updates, or delete). If you inspect the SessionFactory in a debugger and drill down into the registered listeners, you’ll find em.

One of the first questions I had as I added the hibernate-envers.jar was, what is the upgrade path for our existing users? And, more to the point, how can we turn auditing on and off, because surely not everyone is going to want to have all these extra tables filled up all over the place. If you are upgrading SoftSlate as opposed to installing from scratch, the feature should be off by default, until you decide to turn it on. However, as soon as Envers sees those @Audited annotations, it is going to start trying to audit. And if the logging tables don’t exist, it’s going to throw a nasty exception:

Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Table 'softslate_enterprise.sscproduct_aud' doesn't exist.

If the tables do exist, well, it’s going to start filling them up, which you might not want either. So, how to turn this thing on and off? I finally found a reference to this simple property that I can add to hibernate.properties:

hibernate.listeners.envers.autoRegister=false

Sure enough, that did the trick. With that in place, Envers does nothing even if your classes are mapped with @Audited. This is what I needed but I faced another issue with SoftSlate, which is, we don’t distribute hibernate.properties with upgrades, only with new installations. The reason is simply that we don’t want to overwrite that file, because it has your specific database connection settings in it. So for folks who are upgrading, they would have to manually put the above configuration into their hibernate.properties file before upgrading, and we want to avoid making them do that. I realized I wanted to reverse Envers’ default behavior. In other words, instead of registering Envers by default, I want it to start up with Envers disabled by default. I want folks to deliberately enable it by adding this to their own hibernate.properties file:

hibernate.listeners.envers.autoRegister=true

This was relatively easy to do at the moment the SessionFactory is created and right after the properties are loaded from hibernate.properties:

// Set hibernate.listeners.envers.autoRegister to false, unless it's
// deliberately set to true (reverse the regular behavior), so folks
// have to enable it deliberately.
Properties configurationProps = getHibernateSettings();
if (configurationProps.getProperty("hibernate.listeners.envers.autoRegister") == null) {
	configurationProps.setProperty("hibernate.listeners.envers.autoRegister", "false");
}
configuration.setProperties(getHibernateSettings());

We are adding the property to the Hibernate configuration if doesn’t already exist, and setting it to false, in effect reversing the behavior that Envers is enabled by default. Now existing users can upgrade with no worries about anything breaking. If they then wish to leverage Envers, they can manually add hibernate.listeners.envers.autoRegister=true to their properties file.

Tracking Which Entities (ie Tables) Were Changed in Each Revision

Envers has a few bells and whistles, and after playing around with them, I realized we wanted all of bells and all of the whistles enabled, because it’s all good stuff.

org.hibernate.envers.track_entities_changed_in_revision=true

Having this enabled populates a table named REVCHANGES like so:

mysql> SELECT * FROM softslate_enterprise.sscREVCHANGES;
+-----+------------------------------------------------------------+
| REV | ENTITYNAME                                                 |
+-----+------------------------------------------------------------+
|   6 | com.softslate.commerce.businessobjects.product.ProductBean |
|   7 | com.softslate.commerce.businessobjects.product.ProductBean |
+-----+------------------------------------------------------------+
2 rows in set (0.00 sec)

The use case here is say you are auditing 50 tables. Now you have a “revision” and you want to look at what changed across the entire database in that revision. For example, you might find that something weird happened in sscOrder in revision 422, and you might want to look at everything that happened in all the other tables in the same revision. (By the way, a “revision” essentially means a snapshot of the state of the database after each transaction is committed.) This could prove very annoying when you have 50 tables. You have to ask all 50 audit tables if they have something for that revision:

SELECT * FROM sscAudAdministrator WHERE REV=422;
SELECT * FROM sscAudAdministratorRole WHERE REV=422;
SELECT * FROM sscAudAttribute WHERE REV=422;
...

50 select statements. This REVCHANGES table just gives you a shortcut because it tells you which of the 50 classes or tables actually changed. So you know which tables to look in.

Tracking When Records Are Deleted

I definitely recommend adding the following property:

org.hibernate.envers.store_data_at_delete=true

Otherwise, you wont really be able to tell what was deleted. Yes, it will record the primary key of the deleted record but that is not very useful, when the record is gone. This property tells Envers to store the data of the final revision of the entity, right before it is deleted. Could very well come in handy.

Deleting When Auditing Mapped Collections without all-delete-orphan

On the topic of deleting records, I was having a hard time with the following exception when DELETING my Category entity:

org.hibernate.AssertionFailure: Unable to perform beforeTransactionCompletion callback
...
Caused by: java.lang.NullPointerException
        at org.hibernate.engine.internal.StatefulPersistenceContext.getLoadedCollectionOwnerOrNull(StatefulPersistenceContext.java:752)

I had no idea what was going on so I started adding @NotAudited to the collections properties in my Category entity. I started by not auditing all of the collections properties, and sure enough that worked and I could delete again. Then I started auditing each one and I narrowed it down to my Category.products and Category.subcategoryCollection properties. I further narrowed it down to the fact that the thing these two collections have in common that the other collection mappings do not, is that their cascade attribute is not all-delete-orphan:

<set
	name="subcategoryCollection"
	lazy="true"
	table="Category"
	cascade="none"
	order-by="categoryOrder"
	inverse="true">
	<cache usage="read-write"/>
	<key>
		<column name="parentCategory" not-null="false"/>
	</key>
	<one-to-many class="com.softslate.commerce.businessobjects.product.Category"/>
</set>

<set
	name="products"
	lazy="true"
	table="Product"
	cascade="save-update"
	order-by="productOrder"
	inverse="true">
	<cache usage="read-write"/>
	<key>
		<column name="primaryCategoryID" not-null="false"/>
	</key>
	<one-to-many class="com.softslate.commerce.businessobjects.product.Product"/>
</set>

<set
	name="productCategories"
	lazy="true"
	table="ProductCategory"
	cascade="all-delete-orphan"
	order-by="productCategoryOrder"
	inverse="true">
	<cache usage="read-write"/>
	<key>
		<column name="categoryID"/>
	</key>
	<one-to-many class="com.softslate.commerce.businessobjects.product.ProductCategory"/>
</set>

Just to verify I changed the two mappings to all-delete-orphan and sure enough, the deletes work fine. I’m still unclear as to why Envers doesn’t like these mappings – seems like they should be perfectly valid. I really don’t want to cascade deletes here – I don’t want to delete the subcategories under a parent category when the parent category is deleted. Might be something else I’m doing wrong. In the meantime, I’m leaving @NotAudited in there for those two.

Which got me thinking, is it really that interesting to audit collections? Particularly if the child is being audited itself, do I really need to know that a given category’s set of products changed? I think it might be enough to know, from the product’s perspective for example, that its primary category changed. I’m pondering adding @NotAudited to all the collection properties everywhere. I’m also wishing Envers had a configuration that lets me do this globally.

Tracking Which Fields Were Changed

org.hibernate.envers.global_with_modified_flag=true

Without this set to true, the logging tables simply record a snapshot of the fields being audited each time a change is made. It’s up to you to compare each audit log record with the previous one for the same entity, if you want to know what actually changed. Setting org.hibernate.envers.global_with_modified_flag=true tracks not only the values of each audited field, but also whether it changed from the previous version. It seems useful, although it does add twice as many columns to the audit tables. For each audited field, a corresponding boolean field is added, which simply flags whether or not the corresponding field changed during the revision. For example, here you can see that in REV 13 the “name” field changed, by seeing that name_MOD=1:

mysql> mysql> SELECT roleID, REV, REVTYPE, roleID_MOD+0, code, code_MOD+0, name, name_MOD+0, description, description_MOD+0, administratorRoles_MOD+0 FROM softslate_enterprise.sscAudRole;
+--------+-----+---------+--------------+----------+------------+---------------+------------+------------------+-------------------+--------------------------+
| roleID | REV | REVTYPE | roleID_MOD+0 | code     | code_MOD+0 | name          | name_MOD+0 | description      | description_MOD+0 | administratorRoles_MOD+0 |
+--------+-----+---------+--------------+----------+------------+---------------+------------+------------------+-------------------+--------------------------+
|    132 |   5 |       0 |            1 | awefawef |          1 | testing test  |          1 |                  |                 1 |                        0 |
|    132 |   6 |       1 |            1 | awefawef |          1 | testing test  |          1 | Test description |                 1 |                        0 |
|    132 |   8 |       2 |            1 | NULL     |          1 | NULL          |          1 | NULL             |                 1 |                        1 |
|    133 |  11 |       0 |            1 | awefawef |          1 | Ends now      |          1 | Test description |                 1 |                        0 |
|    133 |  12 |       1 |            1 | awefawef |          1 | Ends now      |          1 | Test description |                 1 |                        0 |
|    133 |  13 |       1 |            1 | awefawef |          1 | Ends now test |          1 | Test description |                 1 |                        0 |
|    133 |  14 |       2 |            0 | awefawef |          0 | Ends now test |          0 | Test description |                 0 |                        0 |
+--------+-----+---------+--------------+----------+------------+---------------+------------+------------------+-------------------+--------------------------+
7 rows in set (0.00 sec)

During queries it can be a great help to limit the records to those where just the field you are concerned about changed. Otherwise, you’d have to pull out both the one revision, and the previous revision, and compare the two. Which is not impossible, just a bit harder. (Please note in the above query, I’ve had to CAST the bits to ints for it to show up correctly in the mysql terminal application.)

The Modified Flags and Updating Detached Entities

If you are paying attention, you’ll notice there’s a problem in that we have a lot of false positives in the above query. In revision 12, both code_MOD and name_MOD are true, but as you can clearly see, neither the code nor the name actually changed. This threw me for a loop for a while, especially since I didn’t get these false positives in my audit table for Products:

mysql> select productID, REV, REVTYPE, code, code_MOD+0, name, name_MOD+0 from sscAudProduct;
+-----------+-----+---------+-------+------------+---------------+------------+
| productID | REV | REVTYPE | code  | code_MOD+0 | name          | name_MOD+0 |
+-----------+-----+---------+-------+------------+---------------+------------+
|       486 |   1 |       1 | ends  |          0 | Ends now test |          1 |
|       486 |   2 |       1 | ends  |          0 | Ends now      |          1 |
|       486 |  19 |       1 | ends1 |          1 | Ends now      |          0 |
|       486 |  20 |       1 | ends2 |          1 | Ends now      |          0 |
|       486 |  21 |       1 | ends3 |          1 | Ends now      |          0 |
+-----------+-----+---------+-------+------------+---------------+------------+
5 rows in set (0.01 sec)

Turns out there was subtle difference in how I was updating Roles vs. Products. In the code, when updating Roles, I ran session.update against a detached Role object. In this scenario, Envers sees all the fields as being modified (possibly because there is no existing entity bean in the Hibernate session that has become “dirty”). By contrast in the case of Products, our code first loads the Product entity into the Hibnerate session, and then adjusts the properties, before calling session.update. I fixed the issue with Roles by switching it to use the same pattern of loading the entity first, and sure enough the _MOD fields have no more false positives.

As part of our upcoming release, we have changed the behavior for all our entities to load them first so as to make the _MOD fields accurate. (As of this writing however, you may still see this problem for Orders.) While I think I understand why this is happening, it seems like a bug to me with Envers. You should be able to run session.update against a detached object, have it update, and Envers should be able to track which fields were changed and which were not. (Or, make it clear that it can’t.)

Tracking When a Revision Was Replaced

org.hibernate.envers.audit_strategy=org.hibernate.envers.strategy.ValidityAuditStrategy
org.hibernate.envers.audit_strategy_validity_store_revend_timestamp=true

These two properties can be very valuable because when enabled Envers will store both the revision when a change first took place, and the revision when the record was modified afterwards. It also stores the timestamp of when the revision was replaced, which can be used to purge the audit tables. To be precise, they add the columns REVEND and REVEND_TSTMP to each of the audit tables:

mysql> select productID, REV, REVTYPE, REVEND, REVEND_TSTMP, code, code_MOD+0, unitPrice, unitPrice_MOD+0 from sscAudProduct where code = 'test-product';
+-----------+-----+---------+--------+---------------------+--------------+------------+-----------+-----------------+
| productID | REV | REVTYPE | REVEND | REVEND_TSTMP        | code         | code_MOD+0 | unitPrice | unitPrice_MOD+0 |
+-----------+-----+---------+--------+---------------------+--------------+------------+-----------+-----------------+
|       491 |  59 |       0 |     61 | 2016-05-25 14:20:10 | test-product |          1 |        12 |               1 |
|       491 |  61 |       1 |     62 | 2016-05-25 14:20:53 | test-product |          0 |        15 |               1 |
|       491 |  62 |       1 |   NULL | NULL                | test-product |          0 |        20 |               1 |
+-----------+-----+---------+--------+---------------------+--------------+------------+-----------+-----------------+
3 rows in set (0.00 sec)

Now, to find out what price the product changed from most recently, you can do so with a simple join on REVEND = REV to grab the previous change. REVEND identifies the subsequent revision that replaced the log entry.

Another advantage of REVEND and REVEND_TSTMP specifically is they help if you need to purge old audit logs from time to time. It should be obvious that if the application is very busy, the audit tables will get large over time. Storing the timestamp of when a given revision was replaced makes it easier to develop a purging mechanism. You can now write a query like this:

DELETE FROM sscAudProduct WHERE REVEND_TSTMP < '2016';

And presto, you have purged the audit records prior to a given date. This just gives you some flexibility in terms of archiving and managing the audit records.

One issue with enabling these properties is, it doesn't work if you are adding Envers to a database that has existing tables, unless you first seed the logging tables with the data from your existing tables. The following exception is thrown because it can't find the previous revision for the record when editing a record that already existed (and thus can't update its REVEND field):

org.hibernate.AssertionFailure: Unable to perform beforeTransactionCompletion callback
Caused by: java.lang.RuntimeException: Cannot update previous revision for entity com.softslate.commerce.businessobjects.product.ProductBean_AUD and id 486

I understand the rationale for throwing an exception in this case. If you are relying on these audit logs to be an airtight representation of the changes made to the system, you'll want to throw an exception and terminate the transaction if there is any sort of problem with the audit table updates. Can't update the audit logs? Then NO TRANSACTION FOR YOU.

However, I can also imagine many situations where throwing an exception here is overkill. The audit logs can still be quite useful, if not 100% airtight, if the system fails to update REVEND sometimes. So for our implementation, we replaced the built in ValidityAuditStrategy that handled the REVEND updates with our own version. All our version does differently is swallow the exceptions and log them. This allows the transaction to complete. Yes, REVEND fails to update but we find we can live with that in most cases. Fortunately Envers made it easy to override the default behavior here. We simply modified the audit_strategy property in hibernate.properties to use our own class:

org.hibernate.envers.audit_strategy=com.softslate.commerce.daos.core.AppValidityAuditStrategy

Another advantage of this approach is that you don't have to run all INSERTs through Hibernate. Because we are swallowing the exceptions, we can insert records directly into the database without creating an initial audit log entry.

All of this is not necessary and you can use the default ValidityAuditStrategy if you seed all the audit tables with existing data before turning it on. Which leads us to the next section:

Seeding the Logging Tables with Existing Data

As mentioned above, you can't track when revisions are replaced in Envers unless either (a) you are starting completely from scratch with your database or (c) you override Enver's default ValidityAuditStrategy with something like SoftSlate's AppValidityAuditStrategy, that swallows the exceptions, or (b) you first seed the logging tables from the data in your existing tables. If you can't do (a) or (b) though, seeding the existing tables is not too hard fortunately. If you are upgrading SoftSlate, for example, before turning Envers on, you'll can run the following SQL file from the upgrade distribution: /WEB-INF/src/resources/envers/seed_audit_tables.sql

Here's a quick peek inside that file to show you what it does:

INSERT INTO sscREVINFO (id, timestamp) values (1, 978307200000);

INSERT INTO sscAudAdministrator
(class, administratorID, REV, REVTYPE, userName, password, lastLogin, isApiUser, passwordExpires, numberOfFailedLogins, lockedOutUntil, previousPasswords, allowedIPAddresses, isActive)
SELECT
class, administratorID, 1, 0, userName, password, lastLogin, isApiUser, passwordExpires, numberOfFailedLogins, lockedOutUntil, previousPasswords, allowedIPAddresses, isActive FROM sscAdministrator;

INSERT INTO sscAudAdministratorRole
(class, administratorRoleID, REV, REVTYPE, administratorID, roleID)
SELECT
class, administratorRoleID, 1, 0, administratorID, roleID FROM sscAdministratorRole;

...

Note that we have to insert our first revision record into sscREVINFO, with an id of 1 and a timestamp (this one corresponds to 2010 to avoid any overlap with new records!). From there, it is a simple matter of inserting one record in the logging table for each existing record in the table being monitored, to provide a baseline revision for the database.

Obviously, this will come close to doubling the size of your database quite quickly! So try it out in a development environment first and give some consideration to which tables and fields you need to audit. By default, SoftSlate audits most tables (not sscRequestLog, sscEmail, or any of the Quartz tables), and most fields. Also from above, if you are upgrading you must deliberately add this to your hibernate.properties file for auditing to be enabled:

hibernate.listeners.envers.autoRegister=true

As a summary of the above sections, here's what our default Envers configuration settings look like in hibernate.properties:

hibernate.listeners.envers.autoRegister=false # Must set to true to enable Envers
org.hibernate.envers.track_entities_changed_in_revision=true
org.hibernate.envers.global_with_modified_flag=true
org.hibernate.envers.store_data_at_delete=true
org.hibernate.envers.audit_strategy=org.hibernate.envers.strategy.ValidityAuditStrategy
org.hibernate.envers.audit_strategy_validity_store_revend_timestamp=true

Reports from Audit Data

Now for the good stuff - getting some sweet reports out of the auditing tables. I'll give a few examples of reports represented by just a query made directly against the database. As of this writing we're looking into making a formal interface for some of these queries in the Administrator.

Example Report: Financial History of an Order

This first report sort of tells the financial "story" of an order after it was placed:

SELECT ao.REV, rl.customerUserName, rl.administratorUserName,
     rl.servletPath, rl.created, ao.orderNumber, ao.quantity,
     ao.subtotal, ao.shipping, ao.tax, ao.total
FROM
    (SELECT requestLogID, MAX(id) as REV, MAX(timestamp) as timestamp
        FROM sscREVINFO GROUP BY requestLogID)
    as lastRevInRequest
JOIN sscRequestLog rl ON lastRevInRequest.requestLogID = rl.requestLogID
JOIN sscAudOrder ao on ao.REV = lastRevInRequest.REV
WHERE ao.completed is not null
ORDER BY ao.REV;

+-----+----------------------+-----------------------+-------------------------------------+-------------------------+-------------+----------+--------------------+----------+------+--------+
| REV | customerUserName     | administratorUserName | servletPath                         | created                 | orderNumber | quantity | subtotal           | shipping | tax  | total  |
+-----+----------------------+-----------------------+-------------------------------------+-------------------------+-------------+----------+--------------------+----------+------+--------+
|  24 | dtobey@softslate.com | admin                 | /CheckoutConfirm.do                 | 2016-05-08 20:37:42:684 |        1007 |        3 |             450.65 |       10 |    0 | 460.65 |
|  33 | dtobey@softslate.com | admin                 | /administrator/AddItemProcess.do    | 2016-05-08 20:38:14:341 |        1007 |        4 |             558.36 |       10 |    0 | 568.36 |
|  41 | dtobey@softslate.com | admin                 | /administrator/RemoveItemProcess.do | 2016-05-08 20:38:19:782 |        1007 |        3 |             411.84 |       10 |    0 | 421.84 |
|  49 | dtobey@softslate.com | admin                 | /administrator/AddItemProcess.do    | 2016-05-08 20:38:28:071 |        1007 |        4 |             540.93 |       10 |    0 | 550.94 |
|  57 | dtobey@softslate.com | admin                 | /administrator/AddCouponProcess.do  | 2016-05-08 20:39:36:492 |        1007 |        4 |             459.80 |       10 |    0 |  469.8 |
+-----+----------------------+-----------------------+-------------------------------------+-------------------------+-------------+----------+--------------------+----------+------+--------+
5 rows in set (0.00 sec)

If you look at the financial fields on the far right of the query output, you'll get a history of the order totals for this order - when the totals went up or down. Plus, with the administratorUserName and servletPath columns, you can understand both who made the changes and what requests were sent to the server to make them.

Let's explain the query a bit:

• lastRevInRequest. You'll notice there is a fun derived table in this query. Don't fear it! This is simply filtering out the revisions in the audit table to just those that correspond to the last time the record changed in a given application request. Each time SoftSlate takes in a request, it writes a record to the sscRequestLog table and assigns a "requestLogID". But during the course of a given request, a given record might change multiple times. For example, when adding an item to the cart, the sscOrder record for the cart will be updated once after the item is added and again after discounts are applied. You'll end up with multiple REVs in sscAudOrder for the same request. Most of time, we're not concerned about these intermediate revisions. We're really only concerned about the last revision for each request - what the request turned the record into when it was done doing its work. The derived table simply filters out all these intermediate revisions.
• sscRequestLog and sscREVINFO.requestLogID. SoftSlate extends Envers’ revision entity so we can store the requestLogID of each request in the sscREVINFO table. This allows us to join it with sscRequestLog, where a bunch of other useful information lives, such as the user name of the person making the request, the request URL, the timestamp of the request (although that is already in sscREVINFO), the user’s IP address, and more. (It should be said that request logging is only available with the Enterprise Edition.)

Example Report: The Last Change Made to a Product

Next up, let’s focus in products. Our goal is to find out when someone last changed a given product’s price. We’ll use the REVEND column to quickly pull out the previous audit record for the product:

mysql> select rl.administratorUserName, c.productID, c.REV as current_rev, p.REV as previous_rev, p.REVEND_TSTMP when_changed, c.code, c.unitPrice as current_price, p.unitPrice as prev_price from sscAudProduct c join sscAud p on c.REV=p.REVEND and c.productID = p.productID join sscREVINFO ri on c.REV = ri.id JOIN sscRequestLog rl on ri.requestLogID = rl.requestLogID where c.REVEND IS NULL AND c.code = 'test-product';
+-----------------------+-----------+-------------+--------------+---------------------+--------------+---------------+------------+
| administratorUserName | productID | current_rev | previous_rev | when_changed        | code         | current_price | prev_price |
+-----------------------+-----------+-------------+--------------+---------------------+--------------+---------------+------------+
| admin                 |       491 |          62 |           61 | 2016-05-25 14:20:53 | test-product |            20 |         15 |
+-----------------------+-----------+-------------+--------------+---------------------+--------------+---------------+------------+
1 row in set (0.00 sec)

To analyze the query a bit:

• from sscAudProduct c join sscAud p on c.REV=p.REVEND and c.productID = p.productID
  This joins sscAudProduct with itself. It pulls the current state of the record, and the previous state. This is easy to do because of REVEND. The value of REVEND is populated each time the product changes, and it is populated with the value of the new REV of the new revision. It allows for a quick way to compare two changes that happened.
• join sscREVINFO ri on c.REV = ri.id JOIN sscRequestLog rl on ri.requestLogID = rl.requestLogID
  Here we’re joining sscREVINFO and from there sscRequestLog, in order to find out who did it (rl.administratorUserName). Note: you have to have request logging turned on for sscREVINFO.requestLogID to be populated (available with the Enterprise Edition).
• where c.REVEND IS NULL
  This identifies the current revision. REVEND starts out as null. It is only populated when the record changes next. So for this product, REVEND is null for the current values in the table that is being audited.