Overview

Audit Log was introduced in ProxySQL since version 2.0.5 .

This feature allows to track certain connection activities. Since ProxySQL is often used as the single point of access for the whole database infrastructure, it is often very important to monitor access to ProxySQL and the database setup behind ProxySQL itself. ProxySQL Audit Log solves exactly this requirement.

To enable this feature, the variable mysql-auditlog_filename needs to be configured to specify a file where the logging will be performed. The default value of this variable is an empty string: no logging is enabled by default.

When enabled, the following events are logged:

  • on MySQL Module:
    • successful authentication
    • failed authentication
    • graceful disconnect
    • closed connection
    • change of schema (COM_INIT_DB)
  • on Admin Module:
    • successful authentication
    • failed authentication
    • graceful disconnect
    • closed connection

Further extensions are expected in the future, specifically:

  • support for change of user (COM_CHANGE_USER) on MySQL Module
  • support for events on SQLite3 Server Module
  • support for events on ClickHouse Module

Variables

  • mysql-auditlog_filename : this variable defines the base name of the audit log where audit events are logged. The filename of the log file will be the base name followed by an 8 digits progressive number.The default value is an empty string (“).
  • mysql-auditlog_filesize : this variable defines the maximum file size of the audit log when the current file will be closed and a new file will be created.The default value is 104857600 (100MB).

Logging format

The current implementation supports only one logging format: JSON.

Attributes:

  • client_addr : address (IP:port) of the client connecting to ProxySQL
  • proxy_addr : address (IP:port) of the bind interface where ProxySQL was listening (available only for MySQL module)
  • event : type of event. Current possible values:
    • MySQL_Client_Connect_OK : successful connection to MySQL Module
    • MySQL_Client_Connect_ERR : failed connection to MySQL Module
    • MySQL_Client_Close : MySQL Session being closed
    • MySQL_Client_Quit : client sending an explicit COM_QUIT to MySQL Module
    • MySQL_Client_Init_DB : client sending an explicit COM_INIT_DB to MySQL Module
    • Admin_Connect_OK : successful connection to Admin Module
    • Admin_Connect_ERR : failed connection to Admin Module
    • Admin_Close : Admin Session being closed
    • Admin_Quit : client sending an explicit COM_QUIT to Admin Module
  • time : human readable time of when the event happened, with milliseconds granularity
  • timestamp : epoch time in milliseconds
  • ssl : boolean value that specifies if SSL is being used or not
  • schemaname: the current schema for successful and established connection
  • username: client’s username
  • thread_id: the thread_id (session ID) assigned to the client
  • creation_time : when the session was created, information available only when the session is closed
  • duration : time in milliseconds since the session was created, information available only when the session is closed
  • extra_info : attribute that provides additional information. Currently only used to describe in which part of the code the session is closed.

Audit Log example

Below are some audit log examples.

Detailed example #1:

In the above example below, at the specified time ("time":"2019-05-20 18:48:47.631","timestamp":1558342127631) a client ("client_addr":"127.0.0.1:39954") failed to connect to Admin ("event":"Admin_Connect_ERR"), without using SSL ("ssl":false) using username “admin” ("username":"admin"). To the connection was given an internal thread_id of 2 ("thread_id":2) .

{
 "client_addr":"127.0.0.1:39954",
 "event":"Admin_Connect_ERR",
 "schemaname":"",
 "ssl":false,
 "thread_id":2,
 "time":"2019-05-20 18:48:47.631",
 "timestamp":1558342127631,
 "username":"admin"
}

Next, the same connection described above is disconnected ("event":"Admin_Close") immediately after ("duration":"0.000ms") . Extra information is also provided: "extra_info":"MySQL_Thread.cpp:2652:~MySQL_Thread()".

{
  "client_addr":"127.0.0.1:39954",
  "creation_time":"2019-05-20 18:48:47.631",
  "duration":"0.000ms",
  "event":"Admin_Close",
  "extra_info":"MySQL_Thread.cpp:2652:~MySQL_Thread()",
  "schemaname":"",
  "ssl":false,
  "thread_id":2,
  "time":"2019-05-20 18:48:47.631",
  "timestamp":1558342127631,
  "username":"admin"
}

Detailed example #2:

In the following output we can identify a successful login on Admin module ("event":"Admin_Connect_OK") from "client_addr":"127.0.0.1:43266" , without SSL ("ssl":false) with username admin.

{
  "client_addr":"127.0.0.1:43266",
  "event":"Admin_Connect_OK",
  "schemaname":"main",
  "ssl":false,
  "thread_id":3,
  "time":"2019-05-20 19:16:53.313",
  "timestamp":1558343813313,
  "username":"admin"
}

Next, the client listed above explicitly sends a COM_QUIT command ("event":"Admin_Quit") .

{
  "client_addr":"127.0.0.1:43266",
  "event":"Admin_Quit",
  "schemaname":"main",
  "ssl":false,
  "thread_id":3,
  "time":"2019-05-20 19:16:56.513",
  "timestamp":1558343816513,
  "username":"admin"
}

Finally, the session from the above client is closed ("event":"Admin_Close") after ~3.2 seconds ("duration":"3200.191ms") the client connection was created.

{
  "client_addr":"127.0.0.1:43266",
  "creation_time":"2019-05-20 19:16:53.313",
  "duration":"3200.191ms", "event":"Admin_Close",
  "extra_info":"MySQL_Thread.cpp:2652:~MySQL_Thread()",
  "schemaname":"main",
  "ssl":false,
  "thread_id":3,
  "time":"2019-05-20 19:16:56.513",
  "timestamp":1558343816513,
  "username":"admin"
}

Detailed example #3:

In this example, a client ("client_addr":"127.0.0.1:40822") successfully connects to MySQL module ("event":"MySQL_Client_Connect_OK") on a given bind interface ("proxy_addr":"0.0.0.0:6033") , without SSL ("ssl":false). Username ("username":"sbtest") and schemaname ("schemaname":"mysql") are logged.

{
  "client_addr":"127.0.0.1:40822",
  "event":"MySQL_Client_Connect_OK",
  "proxy_addr":"0.0.0.0:6033",
  "schemaname":"mysql",
  "ssl":false,
  "thread_id":4,
  "time":"2019-05-20 19:20:26.668",
  "timestamp":1558344026668,
  "username":"sbtest"
}

Few seconds after, the same client issues a COM_INIT_DB ("event":"MySQL_Client_Init_DB"), switching schemaname ("schemaname":"sbtest") . This will be recorded:

{
  "client_addr":"127.0.0.1:40822",
  "event":"MySQL_Client_Init_DB",
  "proxy_addr":"0.0.0.0:6033",
  "schemaname":"sbtest",
  "ssl":false,
  "thread_id":4,
  "time":"2019-05-20 19:20:29.902",
  "timestamp":1558344029902,
  "username":"sbtest"
}

In the same example, after few more seconds the client issues a COM_QUIT ("event":"MySQL_Client_Quit"). This will be recorded:

{
  "client_addr":"127.0.0.1:40822",
  "event":"MySQL_Client_Quit",
  "proxy_addr":"0.0.0.0:6033",
  "schemaname":"sbtest",
  "ssl":false,
  "thread_id":4,
  "time":"2019-05-20 19:20:35.759",
  "timestamp":1558344035759,
  "username":"sbtest"
}

Finally, proxysql terminates the session ("event":"MySQL_Client_Close"), that lasted ~9 seconds ("duration":"9091.966ms").

{
  "client_addr":"127.0.0.1:40822",
  "creation_time":"2019-05-20 19:20:26.668",
  "duration":"9091.966ms",
  "event":"MySQL_Client_Close",
  "extra_info":"MySQL_Thread.cpp:3733:process_all_sessions()",
  "proxy_addr":"0.0.0.0:6033",
  "schemaname":"sbtest",
  "ssl":false,
  "thread_id":4,
  "time":"2019-05-20 19:20:35.760",
  "timestamp":1558344035760,
  "username":"sbtest"
}