hgext/serverlog/scripts/parse.py

#!/usr/bin/env python
# This Source Code Form is subject to the terms of the Mozilla Public
# License, v. 2.0. If a copy of the MPL was not distributed with this
# file, You can obtain one at http://mozilla.org/MPL/2.0/.

# This script parses serverlog events into unified messages.

import datetime
import optparse
import sys

hgweb_paths = [
    ("/json-pushes", "hgweb-json-pushes"),
    ("/raw-rev", "hgweb-raw-rev"),
    ("/rev/", "hgweb-rev"),
    ("/raw-file/", "hgweb-raw-file"),
    ("/atom-log", "hgweb-atom-log"),
    ("/static/", "hgweb-static"),
    ("/json-info", "hgweb-json-info"),
    ("/archive", "hgweb-archive"),
    ("/info/refs", "git"),
    ("/diff/", "hgweb-diff"),
    ("/annotate/", "hgweb-annotate"),
    ("/shortlog", "hgweb-shortlog"),
    ("/pushlog", "hgweb-pushlog"),
    ("/pushloghtml", "hgweb-pushloghtml"),
    ("/log/", "hgweb-log"),
    ("/file/", "hgweb-file"),
    ("/comparison/", "hgweb-comparison"),
    ("/filelog/", "hgweb-filelog"),
]


def normalize_path(path):
    for search, command in hgweb_paths:
        try:
            offset = path.index(search)
            return path[0:offset], command
        except ValueError:
            pass

    return path, None


class Request(object):
    def __init__(self, date, repo, ip, url):
        # The repository path that comes in is relative to the hgweb.wsgi file
        # for that repository. And, since some repositories in different
        # directories share the same base name, that means we have to consult
        # the URL to derive the full repo path. Joy.

        # Start by stripping the query string.
        path = url
        if "?" in path:
            path = path[0 : path.find("?")]
        path = path.strip("/")

        path, command = normalize_path(path)

        self.start_date = date
        self.repo = path
        self.ip = ip
        self.url = url
        self.command = command
        self.write_count = None
        self.wall_time = None
        self.cpu_time = None
        self.end_date = None


class SSHSession(object):
    """Represents a full SSH session."""

    def __init__(self, sid, date, repo, username):
        self.id = sid
        self.start_date = date
        self.repo = repo
        self.username = username
        self.commands = []
        self.current_command = None
        self.wall_time = None
        self.cpu_time = None
        self.end_date = None

    @property
    def session_type(self):
        """Determine the type of the session.

        The following types exist:

          push - New changesets were pushed
          pushkey - New keys were set but no changesets were pushed
          pull - Changesets were retrieved
          lookup - Simple repository lookup. Most likely a no-op push or pull.
        """
        commands = set([t[0] for t in self.commands])

        if "unbundle" in commands:
            return "push"

        if "pushkey" in commands:
            return "pushkey"

        if "getbundle" in commands:
            return "pull"

        return "lookup"


def parse_events(fh, onlydate=None):
    thisyear = datetime.date.today().year

    requests = {}
    sessions = {}

    for line in fh:
        date = None
        host = None
        if " hgweb: " in line:
            # Legacy logs: Apr 14 20:17:43
            # New logs: 2016-04-14T20:17:44.250678+00:00
            if line.startswith("20"):
                assert line[26:32] == "+00:00"
                date = datetime.datetime.strptime(line[0:26], "%Y-%m-%dT%H:%M:%S.%f")
                hostaction, line = line[33:].split(":", 1)
                host, action = hostaction.split()
            else:
                date = line[0:15]
                if date[4] == " ":
                    date = date[0:4] + "0" + date[5:]

                # Year isn't in the logs and Python defaults to 1900.
                # This can cause a problem during leap years because strptime
                # will raise a "ValueError: day is out of range for month" for
                # Feb 29. So we add the year to the string before parsing.
                date = "%d %s" % (thisyear, date)
                date = datetime.datetime.strptime(date, "%Y %b %d %H:%M:%S")

                hostaction, line = line[16:].split(":", 1)
                host, action = hostaction.split()

            line = line.strip()
        parts = line.rstrip().split()

        ids, action = parts[0:2]
        ids = ids.split(":")

        if len(ids) > 1:
            session = ids[0]
            request = ids[1]
        else:
            session = None
            request = ids[0]

        if action == "BEGIN_REQUEST":
            if onlydate and date.date() != onlydate:
                continue
            repo, ip, url = parts[2:]
            requests[request] = Request(date, repo, ip, url)

        elif action == "BEGIN_PROTOCOL":
            command = parts[2]
            r = requests.get(request)
            if r:
                if command != "None":
                    r.command = command

        elif action == "END_REQUEST":
            r = requests.get(request)
            if not r:
                continue

            wr_count, t_wall, t_cpu = parts[2:]
            wr_count = int(wr_count)
            t_wall = float(t_wall)
            t_cpu = float(t_cpu)

            r.write_count = wr_count
            r.wall_time = t_wall
            r.cpu_time = t_cpu
            r.end_date = date
            del requests[request]
            yield r

        elif action == "BEGIN_SSH_SESSION":
            if onlydate and date.date() != onlydate:
                continue

            repo, username = parts[2:]
            assert session
            sessions[session] = SSHSession(session, date, repo, username)

        elif action == "END_SSH_SESSION":
            s = sessions.get(session)
            if not s:
                continue

            t_wall, t_cpu = parts[2:]
            t_wall = float(t_wall)
            t_cpu = float(t_cpu)

            s.end_date = date
            s.wall_time = t_wall
            s.cpu_time = t_cpu

            del sessions[session]
            yield s

        elif action == "BEGIN_SSH_COMMAND":
            command = parts[2]
            s = sessions.get(session)
            if s:
                s.current_command = (request, command, date)

        elif action == "END_SSH_COMMAND":
            s = sessions.get(session)
            if not s:
                continue

            t_wall, t_cpu = parts[2:]
            t_wall = float(t_wall)
            t_cpu = float(t_cpu)

            current = s.current_command
            if current and current[0] == request:
                s.commands.append((current[1], current[2], date, t_wall, t_cpu))

            # The request IDs don't match or there is no beginning event.
            # This is weird. We just don't record the command.

            s.current_command = None

        elif action == "CHANGEGROUPSUBSET_START":
            source, count = parts[2:]
            # count = int(count)

        elif action == "WRITE_PROGRESS":
            count = parts[2]
            # count = int(count)


def print_stream(fh, onlydate=None):
    for thing in parse_events(fh, onlydate=onlydate):
        if isinstance(thing, Request):
            r = thing
            if r.start_date:
                d = r.start_date.isoformat()
            else:
                d = "None"
            print(
                "%s %s %s %s %s %s %s"
                % (d, r.repo, r.ip, r.command, r.write_count, r.wall_time, r.cpu_time)
            )
        elif isinstance(thing, SSHSession):
            s = thing
            if s.start_date:
                d = s.start_date.isoformat()
            else:
                d = "None"
            print(
                "%s %s %s %s %s %s %s"
                % (d, s.id, s.repo, s.session_type, s.username, s.wall_time, s.cpu_time)
            )


if __name__ == "__main__":
    parser = optparse.OptionParser()
    parser.add_option("--date", help="Only extract events on the specified date")

    options, args = parser.parse_args()
    date = None
    if options.date:
        dt = datetime.datetime.strptime(options.date, "%Y-%m-%d")
        date = dt.date()

    if args:
        for f in args:
            with open(f, "rb") as fh:
                print_stream(fh, onlydate=date)
    else:
        print_stream(sys.stdin, onlydate=date)