Today I pushed up the initial patch which adds XA support to Drizzle’s transaction log. So, to give myself a bit of a rest from coding, I’m going to blog a bit about the transaction log and show off some of its features.
What is the Transaction Log?
Simply put, the transaction log is a record of every modification to the state of the server’s data. It is similar to MySQL’s binlog, with some substantial differences:
- The transaction log is composed of Google Protobuffer messages. Because of this, it is possible to read the log using a variety of programming languages, as Marcus Eriksson‘s RabbitReplication project demonstrates.
- The transaction log is a plugin[1]. It lives entirely outside of the Drizzle kernel. The advantage of this is that development of the transaction log does not need to be linked with development in the kernel and versioning of the transaction log can happen independently of the kernel.
- Currently, there is only a single log file. MySQL’s binlog can be split into multiple files. This may or may not change in the future. 🙂
- Drizzle’s transaction log is indexed. Among other things, this means that you can query the transaction log directly from within a Drizzle client via DATA_DICTIONARY views. I will demonstrate this feature below.
It is important to also point out that Drizzle’s transaction log is not required for Drizzle replication. This probably sounds very weird to folks who are accustomed to MySQL replication, which depends on the MySQL binlog. In Drizzle, the replication API is different. Although the transaction log can be used in Drizzle’s replication system, it’s not required. I’ll write more on this in later blog posts which demonstrate how the replication system is not dependent on the transaction log, but in this article I just want to highlight the transaction log module.
How Do I Enable the Transaction Log
First things first, let’s see how we can enable the Transaction Log. If you’ve built Drizzle from source or have installed Drizzle locally, you will be familiar with the process of starting up a Drizzle server. To review, here is how you do so:
cd $basedir ./drizzled [options] &
Where $basedir is the directory you built Drizzle or installed Drizzle. For the [options], typically you will need at the very least a --datadir=$DATADIR and a --mysql-protocol-port=$PORT value. For an explanation of the --mysql-protocol-port option, see Eric Day‘s recent article.
To demonstrate, I’ve built a Drizzle server in a local directory of mine, and I’ll use the /tests/var/ directory as my $datadir:
cd /home/jpipes/repos/drizzle/xa-transaction-log/drizzled/ ./drizzled --datadir=/home/jpipes/repos/drizzle/xa-transaction-log/tests/var/ --mysql-protocol-port=9306 &
You should see output similar to this:
jpipes@serialcoder:~/repos/drizzle/xa-transaction-log/drizzled$ ./drizzled --datadir=/home/jpipes/repos/drizzle/xa-transaction-log/tests/var/ --mysql-protocol-port=9306 & [1] 31499 jpipes@serialcoder:~/repos/drizzle/xa-transaction-log/drizzled$ InnoDB: The InnoDB memory heap is disabled InnoDB: Mutexes and rw_locks use GCC atomic builtins. InnoDB: The first specified data file ./ibdata1 did not exist: InnoDB: a new database to be created! 100317 15:41:51 InnoDB: Setting file ./ibdata1 size to 10 MB InnoDB: Database physically writes the file full: wait... 100317 15:41:52 InnoDB: Log file ./ib_logfile0 did not exist: new to be created InnoDB: Setting log file ./ib_logfile0 size to 5 MB InnoDB: Database physically writes the file full: wait... 100317 15:41:52 InnoDB: Log file ./ib_logfile1 did not exist: new to be created InnoDB: Setting log file ./ib_logfile1 size to 5 MB InnoDB: Database physically writes the file full: wait... InnoDB: Doublewrite buffer not found: creating new InnoDB: Doublewrite buffer created InnoDB: Creating foreign key constraint system tables InnoDB: Foreign key constraint system tables created 100317 15:41:53 InnoDB Plugin 1.0.4 started; log sequence number 0 Listening on 0.0.0.0:9306 Listening on :::9306 Listening on 0.0.0.0:4427 Listening on :::4427 ./drizzled: Forcing close of thread 0 user: '' ./drizzled: ready for connections. Version: '2010.03.1314' Source distribution (xa-transaction-log)
To connect to the above server, I then do:
../client/drizzle --port=9306
If all went well, you should be at a drizzle client prompt:
jpipes@serialcoder:~/repos/drizzle/xa-transaction-log/drizzled$ ../client/drizzle --port=9306 Welcome to the Drizzle client.. Commands end with ; or \g. Your Drizzle connection id is 2 Server version: 7 Source distribution (xa-transaction-log) Type 'help;' or '\h' for help. Type '\c' to clear the buffer. drizzle>
You can check to see whether the transaction log is enabled by querying the DATA_DICTIONARY.VARIABLES table. The transaction log is not on by default:
drizzle> use data_dictionary Reading table information for completion of table and column names You can turn off this feature to get a quicker startup with -A Database changed drizzle> SELECT * FROM GLOBAL_VARIABLES WHERE VARIABLE_NAME LIKE 'transaction_log%'; +---------------------------------+-----------------+ | VARIABLE_NAME | VARIABLE_VALUE | +---------------------------------+-----------------+ | transaction_log_enable | OFF | | transaction_log_enable_checksum | OFF | | transaction_log_enable_xa | OFF | | transaction_log_log_file | transaction.log | | transaction_log_sync_method | 0 | | transaction_log_truncate_debug | OFF | | transaction_log_xa_num_slots | 8 | +---------------------------------+-----------------+ 7 rows in set (0 sec)
OK, let’s start up the server, this time with the transaction log enabled. To shutdown Drizzle, there is no need to use a tool like mysqladmin. You can shutdown the server via the client:
drizzle> exit Bye jpipes@serialcoder:~/repos/drizzle/xa-transaction-log/drizzled$ ../client/drizzle --port=9306 --shutdown jpipes@serialcoder:~/repos/drizzle/xa-transaction-log/drizzled$ ./drizzled: Normal shutdown 100317 15:53:48 InnoDB: Starting shutdown... 100317 15:53:49 InnoDB: Shutdown completed; log sequence number 44244 ...
Now let’s start up the server, this time passing the --transaction-log-enable and the --default-replicator-enable options. The --default-replicator-enable option is needed when the transaction log is not in XA mode (more on that later):
jpipes@serialcoder:~/repos/drizzle/xa-transaction-log/drizzled$ ./drizzled --datadir=/home/jpipes/repos/drizzle/xa-transaction-log/tests/var/ --mysql-protocol-port=9306 --transaction-log-enable --default-replicator-enable & [2] 31582 [1] Done ./drizzled --datadir=/home/jpipes/repos/drizzle/xa-transaction-log/tests/var/ --mysql-protocol-port=9306 jpipes@serialcoder:~/repos/drizzle/xa-transaction-log/drizzled$ InnoDB: The InnoDB memory heap is disabled ... ./drizzled: ready for connections.
And again, connect to the server and check our transaction log variables again:
jpipes@serialcoder:~/repos/drizzle/xa-transaction-log/drizzled$ ../client/drizzle --port=9306 Welcome to the Drizzle client.. Commands end with ; or \g. Your Drizzle connection id is 2 Server version: 7 Source distribution (xa-transaction-log) Type 'help;' or '\h' for help. Type '\c' to clear the buffer. drizzle> use data_dictionary Reading table information for completion of table and column names You can turn off this feature to get a quicker startup with -A Database changed drizzle> SELECT * FROM GLOBAL_VARIABLES WHERE VARIABLE_NAME LIKE 'transaction_log%'; +---------------------------------+-----------------+ | VARIABLE_NAME | VARIABLE_VALUE | +---------------------------------+-----------------+ | transaction_log_enable | ON | | transaction_log_enable_checksum | OFF | | transaction_log_enable_xa | OFF | | transaction_log_log_file | transaction.log | | transaction_log_sync_method | 0 | | transaction_log_truncate_debug | OFF | | transaction_log_xa_num_slots | 8 | +---------------------------------+-----------------+ 7 rows in set (0 sec) drizzle>
OK. So, if you check the $datadir, you should see a file called transaction.log, with a size of 0:
jpipes@serialcoder:~/repos/drizzle/xa-transaction-log/drizzled$ ls -lha ../tests/var/ total 21M drwxr-xr-x 6 jpipes jpipes 4.0K 2010-03-17 15:54 . drwxr-xr-x 11 jpipes jpipes 4.0K 2010-03-17 14:57 .. -rw-rw---- 1 jpipes jpipes 10M 2010-03-17 15:54 ibdata1 -rw-rw---- 1 jpipes jpipes 5.0M 2010-03-17 15:54 ib_logfile0 -rw-rw---- 1 jpipes jpipes 5.0M 2010-03-17 15:41 ib_logfile1 -rwxr----- 1 jpipes jpipes 6 2010-03-17 15:54 serialcoder.pid -rwx------ 1 jpipes jpipes 0 2010-03-17 15:54 transaction.log
Back in the drizzle client, let’s go ahead and create a new schema, a new table, and add a single row to that table. This will add some entries to the transaction log that we’ll be able to view:
drizzle> CREATE SCHEMA lebowski; Query OK, 1 rows affected (0.06 sec) drizzle> USE lebowski Database changed drizzle> CREATE TABLE characters (name VARCHAR(20) NOT NULL PRIMARY KEY, -> hobby VARCHAR(10) NOT NULL) ENGINE=InnoDB; Query OK, 0 rows affected (0.06 sec) drizzle> INSERT INTO characters VALUES ('the dude','bowling'); Query OK, 1 row affected (0.05 sec)
Checking in on our transaction log file, we see it now has some size to it:
jpipes@serialcoder:~/repos/drizzle/xa-transaction-log/drizzled$ ls -lha ../tests/var/ total 21M drwxr-xr-x 7 jpipes jpipes 4.0K 2010-03-17 16:11 . drwxr-xr-x 11 jpipes jpipes 4.0K 2010-03-17 14:57 .. -rw-rw---- 1 jpipes jpipes 10M 2010-03-17 16:11 ibdata1 -rw-rw---- 1 jpipes jpipes 5.0M 2010-03-17 16:11 ib_logfile0 -rw-rw---- 1 jpipes jpipes 5.0M 2010-03-17 16:11 ib_logfile1 drwxrwx--x 2 jpipes jpipes 4.0K 2010-03-17 16:11 lebowski -rwxr----- 1 jpipes jpipes 6 2010-03-17 16:11 serialcoder.pid -rwx------ 1 jpipes jpipes 444 2010-03-17 16:11 transaction.log
Finding Out What’s In the Transaction Log
OK, so now for the really cool part of this little demonstration. 🙂 Let’s take a look at what is now contained in the transaction log, all via the Drizzle client and the DATA_DICTIONARY views.
There are currently three DATA_DICTIONARY views which show information about the transaction log and its contents:
- DATA_DICTIONARY.TRANSACTION_LOG
- DATA_DICTIONARY.TRANSACTION_LOG_ENTRIES
- DATA_DICTIONARY.TRANSACTION_LOG_TRANSACTIONS
To see what each view contains, simply do a DESC on them:
drizzle> use data_dictionary Reading table information for completion of table and column names You can turn off this feature to get a quicker startup with -A Database changed drizzle> DESC TRANSACTION_LOG; +---------------------+---------+-------+---------+-----------------+-----------+ | Field | Type | Null | Default | Default_is_NULL | On_Update | +---------------------+---------+-------+---------+-----------------+-----------+ | FILE_NAME | VARCHAR | FALSE | | FALSE | | | FILE_LENGTH | BIGINT | FALSE | | FALSE | | | NUM_LOG_ENTRIES | BIGINT | FALSE | | FALSE | | | NUM_TRANSACTIONS | BIGINT | FALSE | | FALSE | | | MIN_TRANSACTION_ID | BIGINT | FALSE | | FALSE | | | MAX_TRANSACTION_ID | BIGINT | FALSE | | FALSE | | | MIN_END_TIMESTAMP | BIGINT | FALSE | | FALSE | | | MAX_END_TIMESTAMP | BIGINT | FALSE | | FALSE | | | INDEX_SIZE_IN_BYTES | BIGINT | FALSE | | FALSE | | +---------------------+---------+-------+---------+-----------------+-----------+ 9 rows in set (0 sec) drizzle> DESC TRANSACTION_LOG_ENTRIES; +--------------+---------+-------+---------+-----------------+-----------+ | Field | Type | Null | Default | Default_is_NULL | On_Update | +--------------+---------+-------+---------+-----------------+-----------+ | ENTRY_OFFSET | BIGINT | FALSE | | FALSE | | | ENTRY_TYPE | VARCHAR | FALSE | | FALSE | | | ENTRY_LENGTH | BIGINT | FALSE | | FALSE | | +--------------+---------+-------+---------+-----------------+-----------+ 3 rows in set (0 sec) drizzle> DESC TRANSACTION_LOG_TRANSACTIONS; +-----------------+--------+-------+---------+-----------------+-----------+ | Field | Type | Null | Default | Default_is_NULL | On_Update | +-----------------+--------+-------+---------+-----------------+-----------+ | ENTRY_OFFSET | BIGINT | FALSE | | FALSE | | | TRANSACTION_ID | BIGINT | FALSE | | FALSE | | | SERVER_ID | BIGINT | FALSE | | FALSE | | | START_TIMESTAMP | BIGINT | FALSE | | FALSE | | | END_TIMESTAMP | BIGINT | FALSE | | FALSE | | | NUM_STATEMENTS | BIGINT | FALSE | | FALSE | | | CHECKSUM | BIGINT | FALSE | | FALSE | | +-----------------+--------+-------+---------+-----------------+-----------+ 7 rows in set (0 sec)
Let’s see what each of the views tells us about what is in the transaction log. Remember, we’ve executed a CREATE SCHEMA, a CREATE TABLE, and a single INSERT. Here is what the TRANSACTION_LOG view shows:
drizzle> SELECT * FROM TRANSACTION_LOG\G *************************** 1. row *************************** FILE_NAME: transaction.log FILE_LENGTH: 444 NUM_LOG_ENTRIES: 3 NUM_TRANSACTIONS: 3 MIN_TRANSACTION_ID: 1 MAX_TRANSACTION_ID: 3 MIN_END_TIMESTAMP: 1268856698672620 MAX_END_TIMESTAMP: 1268856707093000 INDEX_SIZE_IN_BYTES: 73736
The column names should be self explanatory. The FILE_LENGTH shows the size in bytes of the log (which matches the output we had from our ls -lha above.) The INDEX_SIZE_IN_BYTES is total amount of memory allocated for the transaction log index.
The TRANSACTION_LOG_ENTRIES view isn’t that interesting at first glance:
drizzle> SELECT * FROM TRANSACTION_LOG_ENTRIES; +--------------+-------------+--------------+ | ENTRY_OFFSET | ENTRY_TYPE | ENTRY_LENGTH | +--------------+-------------+--------------+ | 0 | TRANSACTION | 89 | | 89 | TRANSACTION | 223 | | 312 | TRANSACTION | 132 | +--------------+-------------+--------------+
You might be tempted to ask what the heck the purpose of the TRANSACTION_LOG_ENTRIES view is for. It is a bit of a bridge table that allows one to see the type of entries at each offset. Currently, the only types of entries in the transaction log are of type TRANSACTION — basically a serialized GPB Protobuffer message — and a BLOB entry, which is for storage of large blob data.
The TRANSACTION_LOG_TRANSACTIONS view shows all the transaction log entries which are of type TRANSACTION:
drizzle> SELECT * FROM TRANSACTION_LOG_TRANSACTIONS; +--------------+----------------+-----------+------------------+------------------+----------------+----------+ | ENTRY_OFFSET | TRANSACTION_ID | SERVER_ID | START_TIMESTAMP | END_TIMESTAMP | NUM_STATEMENTS | CHECKSUM | +--------------+----------------+-----------+------------------+------------------+----------------+----------+ | 0 | 1 | 1 | 1268856698672606 | 1268856698672620 | 1 | 0 | | 89 | 2 | 1 | 1268856702792284 | 1268856702792331 | 1 | 0 | | 312 | 3 | 1 | 1268856707025455 | 1268856707093000 | 1 | 0 | +--------------+----------------+-----------+------------------+------------------+----------------+----------+ 3 rows in set (0 sec)
As you can see, there is some basic information about each transaction entry in the log, including the offset in the transaction log, the start and end timestamp of the transaction, it’s transaction identifier, the number of statements involved in the transaction, and an optional checksum for the message (more on checksums below).
Viewing the Transaction Content
While the above view output may be nice, what we’d really like to be able to do is see what precisely were the changes a Transaction effected. To see this, we can use the PRINT_TRANSACTION_MESSAGE(log_file, offset) UDF. Below, I’ve added two more rows to the lebowski.characters table within an explicit transaction. I then query the DATA_DICTIONARY views using the PRINT_TRANSACTION_MESSAGE() function to show the changes logged to the transaction log:
drizzle> use lebowski Reading table information for completion of table and column names You can turn off this feature to get a quicker startup with -A Database changed drizzle> START TRANSACTION; Query OK, 0 rows affected (0 sec) drizzle> INSERT INTO characters VALUES ('walter','bowling'); Query OK, 1 row affected (0 sec) drizzle> INSERT INTO characters VALUES ('donny','bowling'); Query OK, 1 row affected (0 sec) drizzle> COMMIT; Query OK, 0 rows affected (0.09 sec)
We now see an additional Transaction Log entry and can see that this transaction contains the two individual INSERT statements just executed:
drizzle> SELECT * FROM TRANSACTION_LOG_TRANSACTIONS; +--------------+----------------+-----------+------------------+------------------+----------------+----------+ | ENTRY_OFFSET | TRANSACTION_ID | SERVER_ID | START_TIMESTAMP | END_TIMESTAMP | NUM_STATEMENTS | CHECKSUM | +--------------+----------------+-----------+------------------+------------------+----------------+----------+ | 0 | 1 | 1 | 1268856698672606 | 1268856698672620 | 1 | 0 | | 89 | 2 | 1 | 1268856702792284 | 1268856702792331 | 1 | 0 | | 312 | 3 | 1 | 1268856707025455 | 1268856707093000 | 1 | 0 | | 444 | 4 | 1 | 1268857926482600 | 1268857938514312 | 1 | 0 | +--------------+----------------+-----------+------------------+------------------+----------------+----------+ ... drizzle> SELECT PRINT_TRANSACTION_MESSAGE('transaction.log', ENTRY_OFFSET) as info -> FROM TRANSACTION_LOG_TRANSACTIONS WHERE ENTRY_OFFSET = 444\G *************************** 1. row *************************** info: transaction_context { server_id: 1 transaction_id: 4 start_timestamp: 1268857926482600 end_timestamp: 1268857938514312 } statement { type: INSERT start_timestamp: 1268857926482605 end_timestamp: 1268857938514310 insert_header { table_metadata { schema_name: "lebowski" table_name: "characters" } field_metadata { type: VARCHAR name: "name" } field_metadata { type: VARCHAR name: "hobby" } } insert_data { segment_id: 1 end_segment: true record { insert_value: "walter" insert_value: "bowling" } record { insert_value: "donny" insert_value: "bowling" } } } 1 row in set (0.01 sec)
You may notice that NUM_STATEMENTS is equal to 1 even though there were 2 INSERT statements issued. This is because the kernel packages both the INSERTs into a single message::Statement::InsertData package for more efficient storage. If there had been an INSERT and an UPDATE, NUM_STATEMENTS would be 2.
Enable Automatic Checksumming
One final feature I’ll highlight in this blog post is an option to automatically store a checksum of each transaction message when writing entries to the transaction log. To enable this feature, simply use the --transaction-log-enable-checksum command line option. You can view the checksums of entries in the TRANSACTION_LOG_TRANSACTIONS view, as demonstrated below:
jpipes@serialcoder:~/repos/drizzle/xa-transaction-log/drizzled$ ./drizzled --datadir=/home/jpipes/repos/drizzle/xa-transaction-log/tests/var/ --mysql-protocol-port=9306 --transaction-log-enable --default-replicator-enable --transaction-log-enable-checksum & [5] 32042 [4] Done ./drizzled --datadir=/home/jpipes/repos/drizzle/xa-transaction-log/tests/var/ --mysql-protocol-port=9306 --transaction-log-enable --default-replicator-enable jpipes@serialcoder:~/repos/drizzle/xa-transaction-log/drizzled$ InnoDB: The InnoDB memory heap is disabled InnoDB: Mutexes and rw_locks use GCC atomic builtins. InnoDB: The first specified data file ./ibdata1 did not exist: InnoDB: a new database to be created! 100317 16:47:07 InnoDB: Setting file ./ibdata1 size to 10 MB InnoDB: Database physically writes the file full: wait... 100317 16:47:07 InnoDB: Log file ./ib_logfile0 did not exist: new to be created InnoDB: Setting log file ./ib_logfile0 size to 5 MB InnoDB: Database physically writes the file full: wait... 100317 16:47:08 InnoDB: Log file ./ib_logfile1 did not exist: new to be created InnoDB: Setting log file ./ib_logfile1 size to 5 MB InnoDB: Database physically writes the file full: wait... InnoDB: Doublewrite buffer not found: creating new InnoDB: Doublewrite buffer created InnoDB: Creating foreign key constraint system tables InnoDB: Foreign key constraint system tables created 100317 16:47:08 InnoDB Plugin 1.0.4 started; log sequence number 0 Listening on 0.0.0.0:9306 Listening on :::9306 Listening on 0.0.0.0:4427 Listening on :::4427 ./drizzled: Forcing close of thread 0 user: '' ./drizzled: ready for connections. Version: '2010.03.1314' Source distribution (xa-transaction-log) ... jpipes@serialcoder:~/repos/drizzle/xa-transaction-log/drizzled$ ../client/drizzle --port=9306 Welcome to the Drizzle client.. Commands end with ; or \g. Your Drizzle connection id is 2 Server version: 7 Source distribution (xa-transaction-log) Type 'help;' or '\h' for help. Type '\c' to clear the buffer. drizzle> CREATE SCHEMA lebowski; Query OK, 1 row affected (0.05 sec) drizzle> CREATE TABLE characters (name VARCHAR(20) NOT NULL PRIMARY KEY, hobby VARCHAR(10) NOT NULL) ENGINE=InnoDB; ERROR 1046 (3D000): No database selected drizzle> use lebowski Database changed drizzle> CREATE TABLE characters (name VARCHAR(20) NOT NULL PRIMARY KEY, hobby VARCHAR(10) NOT NULL) ENGINE=InnoDB; Query OK, 0 rows affected (0.11 sec) drizzle> INSERT INTO characters VALUES ('the dude','bowling'); Query OK, 1 row affected (0.1 sec) drizzle> use data_dictionary Reading table information for completion of table and column names You can turn off this feature to get a quicker startup with -A Database changed drizzle> SELECT ENTRY_OFFSET, TRANSACTION_ID, CHECKSUM FROM TRANSACTION_LOG_TRANSACTIONS; +--------------+----------------+------------+ | ENTRY_OFFSET | TRANSACTION_ID | CHECKSUM | +--------------+----------------+------------+ | 0 | 2 | 143866125 | | 89 | 8 | 1466831622 | | 312 | 9 | 460824986 | +--------------+----------------+------------+ 3 rows in set (0 sec)
DDL is not Statement-based Replication
As a final note, I’d like to point out that even DDL in Drizzle is replicated as row-based transaction messages, and not as raw SQL statements like in MySQL. You can see, for instance, the message::Statement::CreateTableStatement inside the transaction message which contains all the metadata about the table you just created. 🙂
drizzle> SELECT PRINT_TRANSACTION_MESSAGE('transaction.log', ENTRY_OFFSET) -> FROM TRANSACTION_LOG_TRANSACTIONS WHERE ENTRY_OFFSET = 89\G *************************** 1. row *************************** PRINT_TRANSACTION_MESSAGE('transaction.log', ENTRY_OFFSET): transaction_context { server_id: 1 transaction_id: 2 start_timestamp: 1268858897017396 end_timestamp: 1268858897017447 } statement { type: CREATE_TABLE start_timestamp: 1268858897017402 end_timestamp: 1268858897017445 create_table_statement { table { name: "characters" engine { name: "InnoDB" } field { name: "name" type: VARCHAR format: DefaultFormat constraints { is_nullable: false } string_options { length: 20 collation_id: 45 collation: "utf8_general_ci" } } field { name: "hobby" type: VARCHAR format: DefaultFormat constraints { is_nullable: false } string_options { length: 10 collation_id: 45 collation: "utf8_general_ci" } } indexes { name: "PRIMARY" is_primary: true is_unique: true type: UNKNOWN_INDEX key_length: 80 index_part { fieldnr: 0 compare_length: 80 key_type: 0 } options { binary_pack_key: true var_length_key: true } } type: STANDARD options { collation: "utf8_general_ci" collation_id: 45 } } } } 1 row in set (0 sec)
If you like or don’t like what you see, please do get in touch with me or fire off a wishlist to the Drizzle Discuss mailing list. We’d love to hear from ya!
[1] Actually, the transaction log module is a set of plugins.