At some point most applications need some form of logging or tracing. Be it error logging, general execution tracing, or some application-specific event logging. The former two are quite common and a lot of libraries have been designed to support them. The latter one, however, normally requires a custom implementation for each application since the data that we wish to log, the media on which the logs are stored, and the operations that we need to perform on these logs vary greatly from case to case. In this post I am going to show how to implement event logging in C++ applications using the SQLite relational database and the ODB C++ ORM.

In case you are not familiar with ODB, it is an object-relational mapping (ORM) system for C++. It allows you to persist C++ objects to a relational database without having to deal with tables, columns, or SQL, and manually writing any of the mapping code. ODB natively supports SQLite, PostgreSQL, MySQL, Oracle, and Microsoft SQL Server. Pre-built packages are available for GNU/Linux, Windows, Mac OS X, and Solaris and were tested with GNU g++, MS Visual C++, Sun CC, and Clang.

When I said that we will be storing our events in a relational database, some of you might have thought I am crazy. But SQLite is no ordinary relational database. First of all, SQLite is not your typical client-server RDBMS. Rather, it is an extremely small and fast embedded database. That is, it is linked to your application as a library and the actual database is just a file on a disk. And, as a bonus, SQLite also supports in-memory databases.

Ok, maybe you are still not convinced that SQLite is a good fit for event logging. Consider then the benefits: With a relational database we can easily store statically-typed data in our event records. With SQLite we can store the log as a file on a disk, we can have an in-memory log, or some combination of the two (SQLite allows us to save an in-memory database to a file). And don’t forget that SQLite is fully ACID-compliant. This can be especially important for being able to audit the logs with any kind of certainty that they are accurate. Finally, when it comes to operations that we can perform on our logs, it is hard to beat the generality offered by an RDBMS for data querying and manipulation.

Maybe you are almost convinced, but there is just one last problem: who wants to deal with all that SQL from within a C++ application? Well, that’s where ODB comes to the rescue. As we will see shortly, we can take advantage of all these benefits offered by SQLite without having a single line of SQL in our code. Note also that while the below discussion is focused on SQLite, nothing prevents you from using another RDBMS instead. For example, if you needed to store your logs in a central network location, then you could instead use a client-server database such as PostgreSQL.

But enough talking. Let’s see the code. A good example of an application that usually requires logging is a game server. The log could contain, for example, information about when players entered and left the game. However, for this post I’ve decided to use something less typical: an automated stock trading system. Here we would like to keep an accurate log of all the buy/sell transactions performed by the system. This way we can later figure out how come we lost so much money.

Our event record, as a C++ class, could then look like this (I am omitting accessors and instead making all the data members public for brevity):

 
enum order_type {buy, sell};
 
class event
{
public:
  event (order_type type,
         const std::string& security,
         unsigned int qty,
         double price);
 
  order_type order;
  std::string security;
  unsigned int qty;
  double price;
  boost::posix_time::ptime timestamp;
};
 
std::ostream& operator<< (std::ostream&, const event&);
 

The event class constructor initializes the first four data members with the passed values and sets timestamp to the current time. Here I choose to use Boost date-time library to get a convenient time representation. Other alternatives would be to use QDateTime from Qt or just have an unsigned long long value that stores time in microseconds.

Ok, we have the event class but how do we store it in an SQLite database? This is actually pretty easy with ODB. The only two modifications that we have to make to our class are to mark it as persistent and add the default constructor, which we can make private:

 
#pragma db object no_id
class event
{
  ...
 
private:
  friend class odb::access;
  event () {}
};
 

The friend declaration grants ODB access to the private default constructor, and to the data members, in case we decide to make them private as well.

You may also be wondering what that no_id clause at the end of #pragma db means? This expression tells the ODB compiler that this persistent class has no object id. Normally, persistent classes will have one or more data members designated as an object id. This id uniquely identifies each instance of a class in the database. Under the hood object ids are mapped to primary keys. However, there are cases where a persistent class has no natural object id and creating an artificial one, for example, an auto-incrementing integer, doesn’t add anything other than performance and storage overheads. Many ORM implementations do not support objects without ids. ODB, on the other hand, is flexible enough to support this use-case.

Our persistent event class is ready; see the event.hxx file for the complete version if you would like to try the example yourself. The next step is to compile this header with the ODB compiler to generate C++ code that actually does the saving/loading of this class to/from the SQLite database. Here is the command line:

odb -d sqlite -s -q -p boost/date-time event.hxx

Let’s go through the options one-by-one: The -d (--database) option specifies the database we are using (SQLite in our case). The -s (--generate-schema) option instructs the ODB compiler to also generate the database schema, that is the SQL DDL statements that create tables, etc. By default, for SQLite, the schema is embedded into the generated C++ code. The -q (--generate-query) option tells the ODB compiler to generate query support code. Later we will see how to use queries to analyze our logs. However, if your application doesn’t perform any analysis or if this analysis is performed off-line by another application, then you can omit this option and save on some generated code. Finally, the -p (--profile) option tells the ODB compiler to include the boost/date-time profile. We need it because we are using boost::posix_time::ptime as a data member in our persistent class (see ODB Manual for more information on ODB profiles).

The above command will produce three new files: event-odb.hxx, event-odb.ixx, and event-odb.cxx. The first file we need to #include into our source code and the third file we need to compile and link to our application.

Now we are ready to log some events. Here is an example that opens an SQLite database, re-creates the schema, and then logs a couple of events. I’ve added a few calls to sleep() so that we can get some time gaps between records:

 
void log (odb::database& db, const event& e)
{
  transaction t (db.begin ());
  db.persist (e);
  t.commit ();
}
 
int main ()
{
  odb::sqlite::database db (
    "test.db",
    SQLITE_OPEN_READWRITE | SQLITE_OPEN_CREATE);
 
  // Create the database schema.
  //
  {
    transaction t (db.begin ());
    schema_catalog::create_schema (db);
    t.commit ();
  }
 
  // Log some trading events.
  //
  log (db, event (buy,  "INTC", 100, 25.10));
  log (db, event (buy,  "AMD",  200, 4.05));
  log (db, event (buy,  "ARM",  200, 26.25));
  sleep (1);
  log (db, event (sell, "AMD",  50,  5.45));
  log (db, event (buy,  "ARM",  300, 25.35));
  log (db, event (sell, "INTC", 100, 24.45));
  sleep (1);
  log (db, event (sell, "AMD",  100, 4.45));
  log (db, event (sell, "ARM",  150, 27.75));
}
 

We are now ready to build and run our example (see driver.cxx for the complete version). Here is the command line I used on my GNU/Linux box:

 
g++ -o driver driver.cxx event-odb.cxx -lodb-boost \
  -lodb-sqlite -lodb -lboost_date_time
 

If we now run this example, it takes a few seconds (remember the sleep() calls) and finishes without any indication of whether it was successful or not. In a moment we will add some querying code to our example which will print returned log records. In the meantime, however, we can fire up the sqlite3 utility, which is a command line SQL client for SQLite, and examine our database:

 
$ sqlite3 test.db
sqlite> select * from event;
 
0|INTC|100|25.1|2012-07-29 15:56:39.317903
0|AMD|200|4.05|2012-07-29 15:56:39.318812
0|ARM|200|26.25|2012-07-29 15:56:39.319459
1|AMD|50|5.45|2012-07-29 15:56:40.320095
0|ARM|300|25.35|2012-07-29 15:56:40.321089
1|INTC|100|24.45|2012-07-29 15:56:40.321703
1|AMD|100|4.45|2012-07-29 15:56:41.322475
1|ARM|150|27.75|2012-07-29 15:56:41.323717
 

As you can see, the database seems to contain all the records that we have logged.

Ok, logging was quite easy. Let’s now see how we can run various queries on the logged records. To start, a simple one: find all the transactions involving AMD:

 
typedef odb::query<event> query;
typedef odb::result<event> result;
 
transaction t (db.begin ());
 
result r (db.query<event> (query::security == "AMD"));
 
for (result::iterator i (r.begin ()); i != r.end (); ++i)
  cerr << *i << endl;
 
t.commit ();
 

Or, a much more elegant C++11 version of the same transaction:

 
transaction t (db.begin ());
 
for (auto& e: db.query<event> (query::security == "AMD"))
  cerr << e << endl;
 
t.commit ();
 

If we add this fragment at the end of our driver and run it, we will see the following output:

 
2012-Jul-29 16:03:05.585545 buy 200 AMD @ 4.05
2012-Jul-29 16:03:06.587784 sell 50 AMD @ 5.45
2012-Jul-29 16:03:07.590787 sell 100 AMD @ 4.45
 

What if we were only interested in transactions that happened in, say, the last 2 seconds. That’s also easy:

 
ptime tm (microsec_clock::local_time () - seconds (2));
 
result r (db.query<event> (query::security == "AMD" &&
                           query::timestamp >= tm));
 
for (result::iterator i (r.begin ()); i != r.end (); ++i)
  cerr << *i << endl;
 

Again, if we add this code to the driver and run it, the output will change to:

 
2012-Jul-29 16:03:06.587784 sell 50 AMD @ 5.45
2012-Jul-29 16:03:07.590787 sell 100 AMD @ 4.45
 

I think you get the picture: with ODB we can slice and dice the log in any way we please. We can even select a subset of the record members or run aggregate queries thanks to an ODB feature called views.

Another operation that we may want to perform from time to time is to trim the log. The following code will delete all the records that are older than 2 seconds:

 
ptime tm (microsec_clock::local_time () - seconds (2));
db.erase_query<event> (query::timestamp < tm);
 

What about multi-threaded applications? Can we log to the same database from multiple threads simultaneously. The answer is yes. While it takes some effort to make an SQLite database usable from multiple threads, ODB takes care of that for us. With the release of SQLite 3.7.13, now we can even share an in-memory database among multiple threads (see this note for details).

As you can see, put together, SQLite and ODB can make a pretty powerful yet very simple to setup and use event logging system. It is fast, small, multi-threaded, and ACID compliant. For more information on ODB, refer to the ODB project page or jump directly to the ODB Manual.

This entry was posted on Tuesday, August 7th, 2012 at 8:04 am and is filed under ORM, Design, C++. You can follow any responses to this entry through the RSS 2.0 feed. Both comments and pings are currently closed.