MySQL AUDIT data

Jedan od velikih nedostataka MySQL-a za ozbiljno enterprise okruzenje je auditing. Nekakav minimalan auditing koji enterprise uglavnom zahteva je log
– ko se ulogovao
– kada se ulogovao
– odakle se ulogovao
– da li je logovanje bilo uspesno ili ne
– kada se odlogovao sa servera

Za web je ovo nepotrebno (bez potrebe bi u logu imali informaciju kada se web server zakacio/otkacio) ali za enterprise moze da bude vrlo korisno a vrlo cesto i neophodno, pogotovo kada enterprise aplikacije projektuju polupismeni developeri kojima baza radi autentifikaciju i user permissioning a ne aplikacija „posto im je tako lakse“.

Kao sto rekoh, MySQL ima jako slabu / nikakvu podrsku za auditing. Sve sto MySQL moze je da upali „general query log“ i da u log fajl pise SVE (ko se okacio, kad, i stra je sve radio), ali to ima 2 mane
1. general query log trosi resurse (i do 20% usporenja ne high load aplikacijama)
2. general query log ne pamti neuspele konekcije

Kako je mysql-proxy postao vrlo popularan i koristi se vrlo cesto (sto za load balancing sto u neke druge svrhe) a i sastavni je deo MySQL Enterprise Monitor-a gde sve konekcije idu kroz MEM agent kako bi MEM mogao da pravi analizu upita, koristenje proxy-a za auditing uopste nije tako lose resenje.

Kako bi auditing radio, potrebno je instalirati mysql-proxy (ili agent), namestiti mysql da prima konekcije samo sa proxy-a (staviti ga na neki zaseban port i setovati firewall) a proxy podici na standardnom 3306 portu te ce vase aplikacije bez znanja sav traffic usmeriti kroz proxy.

Skript koji radi neki basic auditing bi izgledao:

function read_auth_result( auth )
  local state = auth.packet:byte()
  if state == proxy.MYSQLD_PACKET_OK then
      print( os.date('%Y-%m-%d %H:%M:%S') .. ":AUTH OK:" 
     .. proxy.connection.server.thread_id .. ":"
     .. proxy.connection.client.username .. ":" 
     .. proxy.connection.client.src.name .. "->" 
     .. proxy.connection.server.dst.name )
  elseif state == proxy.MYSQLD_PACKET_ERR then
      print( os.date('%Y-%m-%d %H:%M:%S') .. ":AUTH FAILED: " 
      .. proxy.connection.server.thread_id .. ":" 
      .. proxy.connection.client.username .. ":" 
      .. proxy.connection.client.src.name .. "->" 
      .. proxy.connection.server.dst.name )
  else
      print( os.date('%Y-%m-%d %H:%M:%S') .. ":AUTH UNKNOWN " 
      .. string.format("%q", auth.packet)  .. ":" 
      .. proxy.connection.client.username .. ":" 
      .. proxy.connection.client.src.name .. "->" 
      .. proxy.connection.server.dst.name )
  end
end
function disconnect_client()
  if proxy.connection.server.thread_id then
      print( os.date('%Y-%m-%d %H:%M:%S') .. ":DISCONNECT:"   
      .. proxy.connection.server.thread_id .. ":" 
      .. proxy.connection.client.username .. ":" 
      .. proxy.connection.client.src.name .. "->" 
      .. proxy.connection.server.dst.name )
  end
end

Ako pogledamo, skript nam loguje vreme, username, thread na mysql-u i sors/destination adrese konekcije. Vidimo kada je neko pokusao da se uloguje na mysql, da li je uspeo ili ne i kada se otkacio.

Log izgleda otprilike ovako:

2010-02-08 17:21:22:AUTH OK:31:arhimed:127.0.0.1:44440->127.0.0.1:3306
2010-02-08 17:21:33:DISCONNECT:31:arhimed:127.0.0.1:44440->127.0.0.1:3306
2010-02-08 17:21:38:AUTH FAILED: 32:arhime:127.0.0.1:44587->127.0.0.1:3306
2010-02-08 17:21:38:DISCONNECT:32:arhime:127.0.0.1:44587->127.0.0.1:3306
2010-02-08 17:21:43:AUTH FAILED: 33:arhie:127.0.0.1:44622->127.0.0.1:3306
2010-02-08 17:21:43:DISCONNECT:33:arhie:127.0.0.1:44622->127.0.0.1:3306


Ako hocemo da logujemo i osnovne podatke o upitima koje korisnik izvrsava onda mozemo prosiriti lua skript:

function read_auth_result( auth )
  local state = auth.packet:byte()
  if state == proxy.MYSQLD_PACKET_OK then
      print( os.date('%Y-%m-%d %H:%M:%S') .. ":AUTH OK:" 
     .. proxy.connection.server.thread_id .. ":"
     .. proxy.connection.client.username .. ":" 
     .. proxy.connection.client.src.name .. "->" 
     .. proxy.connection.server.dst.name )
  elseif state == proxy.MYSQLD_PACKET_ERR then
      print( os.date('%Y-%m-%d %H:%M:%S') .. ":AUTH FAILED: " 
      .. proxy.connection.server.thread_id .. ":" 
      .. proxy.connection.client.username .. ":" 
      .. proxy.connection.client.src.name .. "->" 
      .. proxy.connection.server.dst.name )
  else
      print( os.date('%Y-%m-%d %H:%M:%S') .. ":AUTH UNKNOWN " 
      .. string.format("%q", auth.packet)  .. ":" 
      .. proxy.connection.client.username .. ":" 
      .. proxy.connection.client.src.name .. "->" 
      .. proxy.connection.server.dst.name )
  end
end
function disconnect_client()
  if proxy.connection.server.thread_id then
      print( os.date('%Y-%m-%d %H:%M:%S') .. ":DISCONNECT:"   
      .. proxy.connection.server.thread_id .. ":" 
      .. proxy.connection.client.username .. ":" 
      .. proxy.connection.client.src.name .. "->" 
      .. proxy.connection.server.dst.name )
  end
end
function read_query( packet )
  if string.byte(packet) == proxy.COM_QUERY then
    proxy.queries:append(1, packet, {resultset_is_needed = true} )
    return proxy.PROXY_SEND_QUERY
  end
end
function read_query_result( inj )
  local res         = assert(inj.resultset)
  local raw_len     = assert(res.raw):len()
  local packet      = assert(inj.query)
  local flags       = res.flags
  if res.affected_rows then
    ar = res.affected_rows
  else
    ar = "0"
  end
  print( os.date('%Y-%m-%d %H:%M:%S') 
  .. ":QUERY:" .. proxy.connection.server.thread_id .. ":"
  .. inj.query .. ":"
  .. (inj.query_time / 1000) .. "ms" .. ":"
  .. (inj.response_time / 1000) .. "ms" .. ":"
  .. raw_len .. ":"
  .. tostring(res.flags.no_good_index_used) .. ":"
  .. tostring(res.flags.no_index_used) .. ":"
  .. res.warning_count .. ":"
  .. res.query_status .. ":"
  .. ar 
  )
end

pa nam sada log izgleda malo drugacije:
2010-02-08 17:21:22:AUTH OK:31:arhimed:127.0.0.1:44440->127.0.0.1:3306
2010-02-08 17:21:22:QUERY:31:select @@version_comment limit 1:0.092ms:0.095ms:1:false:false:0:0:0
2010-02-08 17:21:23:QUERY:31:select * from mysql.user:0.281ms:0.305ms:1:false:true:0:0:0
2010-02-08 17:21:24:QUERY:31:select * from mysql.user:0.278ms:0.299ms:1:false:true:0:0:0
2010-02-08 17:21:25:QUERY:31:select * from mysql.user:0.272ms:0.293ms:1:false:true:0:0:0
2010-02-08 17:21:28:QUERY:31:select * from mysql.db:0.229ms:0.243ms:1:false:true:0:0:0
2010-02-08 17:21:33:DISCONNECT:31:arhimed:127.0.0.1:44440->127.0.0.1:3306
2010-02-08 17:21:38:AUTH FAILED: 32:arhime:127.0.0.1:44587->127.0.0.1:3306
2010-02-08 17:21:38:DISCONNECT:32:arhime:127.0.0.1:44587->127.0.0.1:3306
2010-02-08 17:21:43:AUTH FAILED: 33:arhie:127.0.0.1:44622->127.0.0.1:3306
2010-02-08 17:21:43:DISCONNECT:33:arhie:127.0.0.1:44622->127.0.0.1:3306