More Statistics for Slow Queries: log_slow_extra

The slow query log is the trusted old method of recording slow query, so the database administrator can determine which queries are in the most need for optimization. Since MySQL 5.6, it has to some extend been overshadowed by the Performance Schema which has lower overhead and thus allows collecting statistics about all queries. The slow query log has one major advantage though: the data is persisted. In MySQL 8.0.14 which was recently released, there is an improvement for the slow query log: additional statistics about the recorded queries.

The slow query log with log_slow_extra enabled.
The slow query log with log_slow_extra enabled.


Thanks for Facebook for contributing a patch for the new feature.

The additional information is not recorded by default. To enable the feature, enable the log_slow_extra option:

mysql> SET PERSIST log_slow_extra = ON;
Query OK, 0 rows affected (0.05 sec)

Here, SET PERSIST is used, so the configuration change is persisted when MySQL is restarted. If you just want to try the feature, you can use SET GLOBAL, then decide later whether you want to keep it enabled.

That is all that is required. You can now execute a “slow” query and take a look at the recorded data. An easy way to execute a slow query is to execute DO SLEEP(...) where you can replace ... with the number of seconds you want to sleep. However that is not a very interesting query. Another option is to lower long_query_time to ensure your query is captured. If you set long_query_time to zero, all queries are recorded:

mysql> SET SESSION long_query_time = 0.0;
Query OK, 0 rows affected (0.01 sec)

Here SET SESSION is used so only the current connection is affected.

Be Aware

The slow query log does have overhead. It is for most systems not recommended to set long_query_time to zero for all connections all the time. Doing so can cause performance problems.

Finally, execute a query:

mysql> SELECT * FROM ORDER BY Population DESC LIMIT 10;
| ID   | Name             | CountryCode | District         | Population |
| 1024 | Mumbai (Bombay)  | IND         | Maharashtra      |   10500000 |
| 2331 | Seoul            | KOR         | Seoul            |    9981619 |
|  206 | São Paulo        | BRA         | São Paulo        |    9968485 |
| 1890 | Shanghai         | CHN         | Shanghai         |    9696300 |
|  939 | Jakarta          | IDN         | Jakarta Raya     |    9604900 |
| 2822 | Karachi          | PAK         | Sindh            |    9269265 |
| 3357 | Istanbul         | TUR         | Istanbul         |    8787958 |
| 2515 | Ciudad de México | MEX         | Distrito Federal |    8591309 |
| 3580 | Moscow           | RUS         | Moscow (City)    |    8389200 |
| 3793 | New York         | USA         | New York         |    8008278 |
10 rows in set (0.04 sec)

The resulting slow query log record is:

# Time: 2019-01-31T07:24:20.518505Z
# User@Host: root[root] @ localhost [::1]  Id:    15
# Query_time: 0.001827  Lock_time: 0.000087 Rows_sent: 10  Rows_examined: 4089 Thread_id: 15 Errno: 0 Killed: 0 Bytes_received: 0 Bytes_sent: 694 Read_first: 1 Read_last: 0 Read_key: 1 Read_next: 0 Read_prev: 0 Read_rnd: 0 Read_rnd_next: 4080 Sort_merge_passes: 0 Sort_range_count: 0 Sort_rows: 10 Sort_scan_count: 1 Created_tmp_disk_tables: 0 Created_tmp_tables: 0 Start: 2019-01-31T07:24:20.516678Z End: 2019-01-31T07:24:20.518505Z
SET timestamp=1548919460;

The extra data can be a little hard to see due to the formatting of the blog – the extra fields are:

  • Thread_id: 15
  • Errno: 0
  • Killed: 0
  • Bytes_received: 0
  • Bytes_sent: 694
  • Read_first: 1
  • Read_last: 0
  • Read_key: 1
  • Read_next: 0
  • Read_prev: 0
  • Read_rnd: 0
  • Read_rnd_next: 4080
  • Sort_merge_passes: 0
  • Sort_range_count: 0
  • Sort_rows: 10
  • Sort_scan_count: 1
  • Created_tmp_disk_tables: 0
  • Created_tmp_tables: 0
  • Start: 2019-01-31T07:24:20.516678Z
  • End: 2019-01-31T07:24:20.518505Z

As comparison, here is the information for the same query with log_slow_extra = OFF:

# Time: 2019-01-31T07:24:06.100447Z
# User@Host: root[root] @ localhost [::1]  Id:    15
# Query_time: 0.002286  Lock_time: 0.000133 Rows_sent: 10  Rows_examined: 4089
SET timestamp=1548919446;


Automatic Decryption of MySQL Binary Logs Using Python

One of the new features in MySQL 8.0.14 is support for encrypting the binary logs. While encryption makes the data more secure (provided the key is secret of course), it can make life a bit more difficult in terms of how easy it is to do tasks such as point-in-time recoveries. This blog shows how you can use the Python script to decrypt the binary logs as long as you have the keyring that was used to encrypt it.

Decrypting a binary log with

Introduction and Background

João Gramacho wrote a nice blog how you can use standard Linux programs to decrypt the binary logs. This inspired me to consider implementing the same, but using Python which should make the script easier to use. Specifically, my aim was that the Python script should have the following features:

  • It should work cross platform. I have tested the script on Oracle Linux 7 and Microsoft Windows 7.
  • The key used to encrypt binary logs can be rotated, so different binary logs use different keys. The script should automatically determine which key a binary log uses and extract if from the keyring. For simplicity, I only implemented support for the keyring_file plugin.
  • The script should be able to handle multiple binary logs and gracefully handle unencrypted binary logs.


As it turned out once I understood how the keyring file works, the task was pretty straight forward using João’s blog to get the required steps. I have maintained the overall steps from that blog. The result can be downloaded from the following link:


I would like to say a big thank you to João Gramacho and Ivan Švaljek for tips on how to work with the keyring_file data format.

Some important comments about the script are:

  • The script only works with Python 3 (tested with Python 3.6).
  • All work is done in-memory. While this gives good performance (a 1.1GiB binary log on my laptop decrypts in around three seconds when the encrypted log is in the operating system I/O cache), it does mean that the memory usage is quite high. The 1.1GiB file resulted in a 3.2GiB peak memory usage.
  • Other than performing checks of the binary log content, I have added limited error checking. This is to keep focus on the actual work required to decrypt the binary log.
  • The cryptography module is used for the decryption work. The easiest way to install the module is to use pip (see below).
  • The keyring must be from the keyring_file plugin and using format version 2.0 (the format current as of MySQL 8.0.14). If you use a different keyring plugin, you can use the keyring migration feature to create a copy of the keyring using keyring_file. (But, please note that keyring_file is not a secure keyring format.)


The script uses the low-level methods of the cryptography module (the hazmat sub module – named so for a good reason). This is OK in this case as it is pure decryption. However, for encryption please do not use the hazmat methods unless you really know what you are doing.

Installing Prerequisites

If you are using Oracle Linux 7, Red Hat Enterprise Linux (RHEL) 7, or CentOS 7, the included Python version is 2.7. This will not work with the script. You can install Python 3.6 in addition to Python 2.7 from the EPEL repository using the following steps (assuming you have already added the EPEL repository):

shell$ yum install python36
shell$ python3.6 -m ensurepip
shell$ python3.6 -m pip install --upgrade pip

This also installs and upgrades the pip command which can be invoked using python3.6 -m pip.

On all platforms, you can install the cryptography module using pip, for example (from Microsoft Windows):

PS:> python -m pip install cryptography
Collecting cryptography
  Downloading (1.5MB)
    100% |████████████████████████████████| 1.5MB 4.7MB/s
Collecting asn1crypto>=0.21.0 (from cryptography)
  Downloading (101kB)
    100% |████████████████████████████████| 102kB 5.8MB/s
Requirement already satisfied: six>=1.4.1 in c:\users\jesper\appdata\local\programs\python\python36\lib\site-packages (from cryptography) (1.11.0)
Collecting cffi!=1.11.3,>=1.8 (from cryptography)
  Downloading (166kB)
    100% |████████████████████████████████| 174kB 5.5MB/s
Collecting pycparser (from cffi!=1.11.3,>=1.8->cryptography)
  Downloading (158kB)
    100% |████████████████████████████████| 163kB 5.2MB/s
Installing collected packages: asn1crypto, pycparser, cffi, cryptography
  Running install for pycparser ... done

If you use Oracle Linux 7, RHEL 7, or CentOS 7, invoke pip using python3.6 -m pip instead.


You can now test the script. Assuming you have two binary logs of which the first is not encrypted and the second is encrypted:

| Log_name      | File_size | Encrypted |
| binlog.000001 |    722755 | No        |
| binlog.000002 |    723022 | Yes       |
3 rows in set (0.01 sec)

You can now use the script as:

PS:> python --keyring_file_data="C:\ProgramData\MySQL\MySQL Server 8.0\keyring" "C:\ProgramData\MySQL\MySQL Server 8.0\data\binlog.000001" "C:\ProgramData\My
SQL\MySQL Server 8.0\data\binlog.000002"
binlog.000001: Binary log is not encrypted. Skipping.
binlog.000002: Keyring key ID for is 'MySQLReplicationKey_59e3f95b-e0d6-11e8-94e8-ace2d35785be_1'
binlog.000005: Successfully decrypted as 'C:\tmp\plain-binlog.000005'

Notice how binlog.000001 is skipped because it is detected that the binary log is not encrypted.

This is just an example. Invoke the script with the --help argument to get a description of all of the options.

The Full Source Code

For reference, here is the full source code for the script:

import sys
import os
import struct
import collections
import hashlib
from cryptography.hazmat.primitives.ciphers import Cipher, algorithms, modes
from cryptography.hazmat.backends import default_backend

def key_and_iv_from_password(password):
    # Based on

    key_length = 32
    iv_length = 16
    required_length = key_length + iv_length
    password = password

    key_iv = hashlib.sha512(password).digest()
    tmp = [key_iv]
    while len(tmp) < required_length:
        tmp.append(hashlib.sha512(tmp[-1] + password).digest())
        key_iv += tmp[-1]

    key = key_iv[:key_length]
    iv = key_iv[key_length:required_length]

    return key, iv

class Key(
        'Key', [
    __slots__ = ()

class Keyring(object):
    _keys = []
    _keyring_file_version = None
    _xor_str = '*305=Ljt0*!@$Hnm(*-9-w;:'.encode('utf-8')

    def __init__(self, keyring_filepath):

    def _read_key(self, data):
        overall_length = struct.unpack('<Q', data[0:8])[0]
        key_id_length = struct.unpack('<Q', data[8:16])[0]
        key_type_length = struct.unpack('<Q', data[16:24])[0]
        user_id_length = struct.unpack('<Q', data[24:32])[0]
        key_length = struct.unpack('<Q', data[32:40])[0]

        key_id_start = 40
        key_type_start = key_id_start + key_id_length
        user_id_start = key_type_start + key_type_length
        key_start = user_id_start + user_id_length
        key_end = key_start + key_length

        key_id = data[key_id_start:key_type_start].decode('utf-8')
        key_type = data[key_type_start:user_id_start].decode('utf-8')
        # The User ID may be blank in which case the length is zero
        user_id = data[user_id_start:key_start].decode('utf-8') if user_id_length > 0 else None
        key_raw = data[key_start:key_end]
        xor_str_len = len(self._xor_str)
        key_data = bytes([key_raw[i] ^ self._xor_str[i%xor_str_len]
                          for i in range(len(key_raw))])

        return Key(key_id, key_type, user_id, key_data)

    def read_keyring(self, filepath):
        keyring_data = bytearray()
        with open(filepath, 'rb') as keyring_fs:
            chunk =
            while len(chunk) > 0:
                chunk =


        # Verify the start of the file is "Keyring file version:"
        header = keyring_data[0:21]
        if header.decode('utf-8') != 'Keyring file version:':
            raise ValueError('Invalid header in the keyring file: {0}'

        # Get the keyring version - currently only 2.0 is supported
        version = keyring_data[21:24].decode('utf-8')
        if version != '2.0':
            raise ValueError('Unsupported keyring version: {0}'

        self._keyring_file_version = version
        keyring_length = len(keyring_data)
        offset = 24
        keys = []
        while offset < keyring_length and keyring_data[offset:offset+3] != b'EOF':
            key_length = struct.unpack('<Q', keyring_data[offset:offset+8])[0]
            key_data = keyring_data[offset:offset+key_length]
            key = self._read_key(key_data)
            offset += key_length

        self._keys = keys

    def get_key(self, key_id, user_id):
        for key in self._keys:
            if key.key_id == key_id and key.user_id == user_id:
                return key

        return None

def decrypt_binlog(binlog, keyring, out_dir, prefix):
    '''Decrypts a binary log and outputs it to out_dir with the prefix
    prepended. The arguments are:

        * binlog - the path to the encrypted binary log
        * keyring - a Keyring object
        * out_dir - the output directory
        * prefix - prefix to add to the binary log basename.
    magic_encrypted = 'fd62696e'
    magic_decrypted = 'fe62696e'

    binlog_basename = os.path.basename(binlog)
    decrypt_binlog_path = os.path.join(
        out_dir, '{0}{1}'.format(prefix, binlog_basename))
    if os.path.exists(decrypt_binlog_path):
        print("{0}: Decrypted binary log path, '{1}' already exists. Skipping"
              .format(binlog_basename, decrypt_binlog_path), file=sys.stderr)
        return False

    with open(binlog, 'rb') as binlog_fs:
        # Verify the magic bytes are correct
        magic =
        if magic.hex() == magic_decrypted:
            print('{0}: Binary log is not encrypted. Skipping.'
                  .format(binlog_basename), file=sys.stderr)
            return False
        elif magic.hex() != magic_encrypted:
            print("{0}: Found invalid magic '0x{1}' for encrypted binlog file."
                  .format(binlog_basename, magic.hex(), file=sys.stderr))
            return False

        # Get the encrypted version (must currently be 1)
        version = struct.unpack('<B',[0]
        if version != 1:
            print("{0}: Unsupported binary log encrypted version '{1}'"
                  .format(binlog_basename, version), file=sys.stderr)
            return False

        # First header field is a TLV: the keyring key ID
        field_type = struct.unpack('<B',[0]
        if field_type != 1:
            print('{0}: Invalid field type ({1}). Keyring key ID (1) was '
                  + 'expected.'.format(binlog_basename, field_type),
            return False

        keyring_id_len = struct.unpack('<B',[0]
        keyring_id ='utf-8')
        print("{0}: Keyring key ID for is '{1}'"
              .format(binlog_basename, keyring_id), file=sys.stderr)

        # Get the key from the keyring file
        key = keyring.get_key(keyring_id, None)

        # Second header is a TV: the encrypted file password
        field_type = struct.unpack('<B',[0]
        if field_type != 2:
            print('{0}: Invalid field type ({1}). Encrypted file password (2) '
                  + 'was expected.'.format(binlog_basename, field_type),
            return False
        encrypted_password =

        # Third header field is a TV: the IV to decrypt the file password
        field_type = struct.unpack('<B',[0]
        if field_type != 3:
            print('{0}: Invalid field type ({1}). IV to decrypt the file '
                  + 'password (3) was expected.'
                  .format(binlog_basename, field_type), file=sys.stderr)
            return False
        iv =

        backend = default_backend()
        cipher = Cipher(algorithms.AES(key.key_data), modes.CBC(iv),
        decryptor = cipher.decryptor()
        password = decryptor.update(encrypted_password) + decryptor.finalize()

        # Generate the file key and IV
        key, iv = key_and_iv_from_password(password)
        nonce = iv[0:8] + bytes(8)
        # Decrypt the file data (the binary log content)
        # The encrypted binary log headers are 512, so skip those, os.SEEK_SET)
        binlog_encrypted_data =

    cipher = Cipher(algorithms.AES(key), modes.CTR(nonce), backend=backend)
    decryptor = cipher.decryptor()
    binlog_decrypted_data = decryptor.update(binlog_encrypted_data)
    binlog_decrypted_data += decryptor.finalize()
    binlog_encrypted_data = None

    # Check decrypted binary log magic
    magic = binlog_decrypted_data[0:4]
    if magic.hex() != magic_decrypted:
        print("{0}: Found invalid magic '0x{1}' for decrypted binlog file."
              .format(binlog_basename, magic.hex()), file=sys.stderr)
        return False

    # Write the decrypted binary log to disk
    with open(decrypt_binlog_path, 'wb') as new_fs:

    print("{0}: Successfully decrypted as '{1}'"
          .format(binlog_basename, decrypt_binlog_path))
    return True

def decrypt_binlogs(args):
    '''Outer routine for decrypted one or more binary logs. The
    argument args is a named touple (typically from the argparse
    parser) with the following members:

       * args.binlogs - a list or tuple of the binary logs to decrypt
       * args.keyring_file_data - the path to the file with the
            kerying data for the keyring_file plugin.
       * args.dir - the output directory for the decrypted binary logs
       * args.prefix - the prefix to prepend to the basename of the
            encrypted binary log filenames. This allows you to output
            the decrypted to the same directory as the encrypted
            binary logs without overwriting the original files.
    keyring = Keyring(args.keyring_file_data)
    for binlog in args.binlogs:
        decrypt_binlog(binlog, keyring, args.dir, args.prefix)

def main(argv):
    import argparse

    parser = argparse.ArgumentParser(
        description='Decrypt one or more binary log files from MySQL Server '
                   +'8.0.14+ created with binlog_encryption = ON. The '
                   +'binary log files have the prefix given with --prefix '
                   +'prepended to their file names.'
                   +'If an output file already exists, the file will be '
        epilog='All work is performed in-memory. For this reason, the'
               +'expected peak memory usage is around three times the'
               +'size of the largest binary log. As max_binlog_size can'
               +'at most be 1G, for instances exlusively executing small'
               +'transactions, the memory usage can thus be up to around'
               +'3.5G. For instances executing large transactions, the'
               +'binary log files can be much larger than 1G and thus the'
               +'memory usage equally larger.')

    parser.add_argument('-d', '--dir', default=os.getcwd(),
        help='The destination directory for the decrypted binary log files. '
             +'The default is to use the current directory.')

    parser.add_argument('-p', '--prefix', default='plain-',
        help='The prefix to prepand to the basename of the binary log file.'
             +'The default is plain-.')

    parser.add_argument('-k', '--keyring_file_data', default=None,
        help='The path to the keyring file. The same as keyring_file_data in '
             +'the MySQL configuration. This option is mandatory.')

    parser.add_argument('binlogs', nargs=argparse.REMAINDER,
                        help='The binary log files to decrypt.')

    args = parser.parse_args()
    if not args.binlogs:
        print('ERROR: At least one binary log file must be specified.\n',

    if not args.keyring_file_data:
        print('ERROR: The path to the keyring file must be specified.\n',


if __name__ == '__main__':

The start of the script is the handling of the keyring. Then follows the code for decrypting the binary logs which has a total of three functions (from bottom and up):

  • main: The function for handling the command line arguments.
  • decrypt_binlogs: Initializes the keyring and loops over the binary logs.
  • decrypt_binlog: Decrypts a single binary log.

For a closer discussion of the individual steps to decrypt the binary log, I recommend you to read João Gramacho’s blog How to manually decrypt an encrypted binary log file.

MySQL Server 8.0.14: Thanks for the Contributions

MySQL 8.0.14 was released earlier in the week, and again we (Oracle) received several contributions that either made it into the release or at least inspired a feature or bug fix. This blog will go through the the changelog notes for these changes. Thank you for the contributions.

Two of the contributions are new features with patches submitted by Facebook, one by Daniel Black, and one of Facebook’s patches from 8.0.13 has updated:

  • A new system variable, log_slow_extra, if enabled, causes the server to write additional fields to slow query log lines that provide information about slow statements. In addition, SET lines written to the log to indicate statement timestamps now use the time from the beginning of statement execution, rather than the time at the end of execution. See The Slow Query Log. Thanks to Facebook for the contribution on which this feature is based. (Bug #27535580, Bug #89637)
  • InnoDB: To reduce the size of core files, the innodb_buffer_pool_in_core_file variable can be disabled to prevent InnoDB buffer pool pages from being written to core files. Thanks to Facebook for the contribution. (Bug #27724476, Bug #90144)
  • Previously, for command options that take a numeric value, the value could be given with a suffix of K, M, or G to indicate a multiplier of 1024, 1024^2 or 1024^3. Now a suffix can also be T, P, and E to indicate a multiplier of 1024^4, 1024^5 or 1024^6. Thanks to Daniel Black for the patch. (Bug #27306931, Bug #89017)
  • The code contributed by Facebook for the feature implemented by Bug#27855592 was updated. (Bug #28950397)

While it is great with new features, bug fixes are equally important. There are three bug fix contributions in 8.0.14:

  • Some typos in server source code were fixed. Thanks to Hyunwoo Park for the contribution. (Bug #26189673, Bug #86565)
  • On Ubuntu, the installed /etc/mysql/mysql.conf.d/default-auth-override.cnf file was mistakenly created with executable mode. Thanks to Evgeniy Patlan (from Percona) for the correction contribution. (Bug #28714840, Bug #92587)
  • Comparing log file names as strings using the memcmp() function resulted in uninitialized memory read errors. The comparison now uses the strncmp() function. Thanks to Zsolt Parragi and Laurynas Biveinis (both from Percona) for their contributions. (Bug #28178776, Bug #90238)

Sometimes it happens there is a contribution for a good idea, but in the end – for one reason or another – a different patch is implemented. I would still like to say thanks. I am aware of two such cases in MySQL 8.0.14:

  • Thanks to Facebook for suggesting the idea of a separate admin port – the new admin_address and admin_port options. (Bug #27847672, Bug #90395)
  • Thanks to Zhenghu Wen for reporting and submitting a patch for the bug that a member might not be able to move from the RECOVERING to the ONLINE state, when it joins a group. (Bug #89582, Bug #27511404)

Thanks to all involved. Keep up the good work. Even if your patch was not used, don’t get discouraged.

MySQL Connector/Python 8.0.14 X DevAPI: Default Schema

The MySQL X DevAPI is the new API that provides a uniform API across the supported programming languages. It has from the beginning supported that you can specify a default schema, when you connect. Originally it was not used for SQL statements. Starting with MySQL 8.0.14 the feature has been extended, so SQL statements take the default schema into consideration as well. This blog will explore how this works using MySQL Connector/Python. If you use a different programming language, the change will work in a similar way.

In order to explore the feature, a sample program is needed. A simple program that prints the MySQL Connector/Python version, queries the city table in the default schema, and either catches the exception or prints the resulting rows will work:

import mysql.connector
import mysqlx
from mysqlx.errors import OperationalError
import pprint

printer = pprint.PrettyPrinter(indent=3)

connect_args = {
    "host": "",
    "port": 33060,
    "user": "pyuser",
    "password": "Py@pp4Demo",
    "schema": "world",

print("MySQL Connector/Python {0}".format(mysql.connector.__version__))

db = mysqlx.get_session(connect_args)
    result = db.sql("SELECT * FROM city WHERE ID = 130").execute()
except OperationalError as err:
    print("Error: {0}".format(err))
    result = None
    columns = [column.column_name for column in result.get_columns()]
    for row in result.fetch_all():
        row_data = dict(zip(columns, row))


Notice how the default schema is set in line 13.

If this program is executed with MySQL Connector/Python 8.0.13 or earlier, the query in line 20 will cause an OperationalError exception:

MySQL Connector/Python version: 8.0.13
Error: No database selected

However, if you execute the code with MySQL Connector/Python 8.0.14, the query executes and queries the city table in the world schema:

MySQL Connector/Python 8.0.14
{  'CountryCode': 'AUS',
    'District': 'New South Wales',
    'ID': 130,
    'Name': 'Sydney',
    'Population': 3276207}

This new behaviour is the same as you would be used to from the traditional API.


If you want to use the default schema with CRUD statements, you can retrieve the default schema with Session.get_default_schema(). That also works in earlier releases of MySQL Connector/Python.

If you want to read more about using the X DevAPI and MySQL Connector/Python in general, then I have written the book MySQL Connector/Python Revealed (see links in the sidebar to the right).