/mysql_watcher/mysql_logger

#!/usr/bin/env python
#
# $LicenseInfo:firstyear=2010&license=mit$
# 
# Copyright (c) 2010, Linden Research, Inc.
# 
# Permission is hereby granted, free of charge, to any person obtaining a copy
# of this software and associated documentation files (the "Software"), to deal
# in the Software without restriction, including without limitation the rights
# to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
# copies of the Software, and to permit persons to whom the Software is
# furnished to do so, subject to the following conditions:
# 
# The above copyright notice and this permission notice shall be included in
# all copies or substantial portions of the Software.
# 
# THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
# IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
# FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
# AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
# LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
# OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
# THE SOFTWARE.
# $/LicenseInfo$
#

"""
Log all queries hitting a particular mysql database
"""

try:
    import psyco
    psyco.full()
except:
    pass

import curses
import curses.wrapper
import getopt
import os.path
import re
import socket
import sys
import time

from dblibs.dbutil import LLQueryStream, remote_mysql_stream

LOG_ROTATION_INTERVAL=3600
MAX_LOGS = 36

QUERY_LOG_RE = re.compile("query.log.(.+).gz")
def rotate_logs(log_path, query_log_file):
    # Fork to do the actual rotation/compression
    print "Rotating query logs"
    if query_log_file:
        query_log_file.close()
    need_gzip = False

    if os.path.exists(log_path+"/query.log"):
        os.rename(log_path+"/query.log", log_path+"/query.log.tmp")
        need_gzip = True
    
    query_log_file = open("%s/query.log" % log_path, "w")

    pid = os.fork()
    if pid:
        return query_log_file

    # Child process actually does the log rotation
    # Delete the oldest
    log_filename = log_path+"/query.log.%d.gz" % (MAX_LOGS)
    if os.path.exists(log_filename):
        os.remove(log_filename)

    for i in range(0, MAX_LOGS):
        # Count down from the max and rename
        n = MAX_LOGS - i
        log_filename = log_path+"/query.log.%d.gz" % n
        if os.path.exists(log_filename):
            os.rename(log_path + ("/query.log.%d.gz" % n), log_path + ("/query.log.%d.gz" % (n+1)))

    if need_gzip:
        # Compress the "first" log (query.log.tmp)
        os.rename(log_path + "/query.log.tmp", log_path + "/query.log.1")
        os.system('gzip -f %s' % (log_path + "/query.log.1"))
    print "Done rotating logs!"
    sys.exit(0)


def watch_host(query_stream, host):
    "Watches query traffic for a particular host.  Returns the overall query counts when exited by breaking"

    # Make output path
    output_path = "./%s" % host
    os.system("mkdir -p %s" % output_path)
    query_log_file = rotate_logs(output_path, None)

    last_log_time = time.time()

    done = False
    count = 0
    try:
        while not done:
            (event_type, query) = query_stream.getNextEvent()

            # Use the start time to determine which hour bin to put the query into
            start_time = query.mStartTime
            start_hour = time.localtime(start_time)[3]
            
            if event_type == "QueryStart":
                query_log_file.write("%f\t%s:%d\t%s\tQueryStart\n" % (query.mStartTime, query.mData['host'], query.mData['port'], query.mData['host_clean']))
                query_log_file.write("%s\n" % (query.mData['query']))
                query_log_file.write("**************************************\n")
                count += 1
            elif (event_type == "QueryResponse"):
                query_log_file.write("%f\t%s:%d\t%s\tQueryResponse\n" % (query.mResponseTime, query.mData['host'], query.mData['port'], query.mData['host_clean']))
                query_log_file.write("%s\n" % (query.mData['query']))
                query_log_file.write("**************************************\n")
            elif event_type == "Quit":
                # Quit is an "instantaneous" query, both start and response
                query_log_file.write("%f\t%s:%d\t%s\tQuit\n" % (query.mStartTime, query.mData['host'], query.mData['port'], query.mData['host_clean']))
                query_log_file.write("%s\n" % (query.mData['query']))
                query_log_file.write("**************************************\n")
                continue
            if not (count % 1000):
                try:
                    os.waitpid(-1, os.WNOHANG)
                except OSError:
                    pass
                if (time.time() - last_log_time) > LOG_ROTATION_INTERVAL:
                    last_log_time = time.time()
                    query_log_file = rotate_logs(output_path, query_log_file)

            
    except KeyboardInterrupt:
        pass
    query_log_file.close()


if __name__ == "__main__":
    opts, args = getopt.getopt(sys.argv[1:], "", ["host="])

    host = None
    for o, a in opts:
        if o in ("--host"):
            host = a
    if not host:
        print "Specify a host using --host="
        sys.exit(1)

    # Start up the stream from the target host and create a file
    # that we can hand to LLQueryStream
    query_stream_file = remote_mysql_stream(host)
    query_stream = LLQueryStream(query_stream_file)

    watch_host(query_stream, host)