# -*- mode: python; coding: utf-8 -*-

import os

import sys

import time

import random

import logging

import traceback

try:

from cStringIO import StringIO

except ImportError:

from StringIO import StringIO

import jsonpickle

try:

import gprof2dot

except ImportError:

gprof2dot = None

import firepython

import firepython.utils

import firepython._const as CONST

from firepython.handlers import ThreadBufferedHandler

__all__ = [

'FirePythonBase',

'FirePythonDjango',

'FirePythonWSGI',

'paste_filter_factory',

]

# add a new backed jsonpickle for Django

# jsonpickle will attempt to import this if default

# jsonpickle libraries are not present

jsonpickle.load_backend('django.utils.simplejson', 'dumps',

'loads', ValueError)

class FirePythonBase(object):

def __init__(self):

raise NotImplementedError("Must be subclassed")

def install_handler(self):

logger = logging.getLogger(self._logger_name)

self._handler = ThreadBufferedHandler()

logger.addHandler(self._handler)

def uninstall_handler(self):

if self._handler is None:

return

logger = logging.getLogger(self._logger_name)

logger.removeHandler(self._handler)

self._handler = None

def _version_check(self, version_header):

firelogger_api_version = version_header.strip()

if firelogger_api_version == '':

logging.info('FireLogger not detected')

return False

if firepython.__api_version__ != firelogger_api_version:

self._client_message += (

'Warning: FireLogger (client) has version %s, but '

'FirePython (server) is version %s. Check http://firelogger.binaryage.com for latest version.' % (firelogger_api_version,

firepython.__api_version__)

)

logging.warning('FireLogger (client) has version %s, but FirePython '

'(server) is version %s. Check http://firelogger.binaryage.com for latest version.', firelogger_api_version,

firepython.__api_version__)

return True

def _password_check(self, token):

if self._password is None:

raise Exception("self._password must be set!")

if not firepython.utils.get_auth_token(self._password) == token:

self._client_message += 'FireLogger password does not match. '

logging.warning('FireLogger password does not match. Logging output won\'t be sent to FireLogger. Double check your settings!')

return False

return True

def _appengine_check(self):

if 'google.appengine' not in sys.modules:

return True # Definitely not running under Google App Engine

try:

from google.appengine.api import users

except ImportError:

return True # Apparently not running under Google App Engine

if os.getenv('SERVER_SOFTWARE', '').startswith('Dev'):

return True # Running in SDK dev_appserver

# Running in production, only allow admin users

if not users.is_current_user_admin():

self._client_message += 'Security: Log in as a project administrator to see FirePython logs (App Engine in production mode). '

logging.warning('Security: Log in as a project administrator to see FirePython logs (App Engine in production mode)')

return False

return True

def _check(self, env):

self._client_message = ''

self._profile_enabled = \

env.get(CONST.FIRELOGGER_PROFILER_ENABLED_HEADER, '') != ''

self._appstats_enabled = \

env.get(CONST.FIRELOGGER_APPSTATS_ENABLED_HEADER, '') != ''

if self._check_agent and not self._version_check(

env.get(CONST.FIRELOGGER_VERSION_HEADER, '')):

return False

if ((self._password and not

self._password_check(

env.get(CONST.FIRELOGGER_AUTH_HEADER, '')))):

return False

# If _password is set, skip _appengine_check()

if (not self._password and not self._appengine_check()):

return False

return True

def _sanitize_exc_info(self, exc_info):

if exc_info == None:

return ("?", "No exception info available", [])

exc_type = exc_info[0]

exc_value = exc_info[1]

exc_traceback = exc_info[2]

if exc_traceback is not None:

exc_traceback = traceback.extract_tb(exc_traceback)

return (exc_type, exc_value, exc_traceback)

def _handle_internal_exception(self, e):

if CONST.RAZOR_MODE: # in razor mode hurt web server

raise e

# in non-razor mode report internal error to firepython addon

exc_info = self._sanitize_exc_info(sys.exc_info())

return {"message": "Internal FirePython error: %s" % unicode(e),

"exc_info": exc_info}

def _encode(self, logs, errors=None, profile=None, extension_data=None):

data = {"logs": logs}

if errors:

data['errors'] = errors

if profile:

data['profile'] = profile

if extension_data:

data['extension_data'] = extension_data

try:

data = jsonpickle.encode(data, unpicklable=False,

max_depth=CONST.JSONPICKLE_DEPTH)

except Exception, e:

# this exception may be fired, because of buggy __repr__ or

# __str__ implementations on various objects

errors = [self._handle_internal_exception(e)]

try:

data = jsonpickle.encode({"errors": errors },

unpicklable=False,

max_depth=CONST.JSONPICKLE_DEPTH)

except Exception, e:

# even unable to serialize error message

data = jsonpickle.encode(

{"errors": {

"message": "FirePython has a really bad day :-("

}

},

unpicklable=False,

max_depth=CONST.JSONPICKLE_DEPTH

)

data = data.encode('utf-8')

data = data.encode('base64')

return data.splitlines()

def republish(self, headers):

firelogger_headers = []

for key, value in headers.iteritems():

if CONST.FIRELOGGER_RESPONSE_HEADER.match(key):

firelogger_headers.append((key, value))

self._handler.republish(firelogger_headers)

def _flush_records(self, add_header, profile=None, extension_data=None):

"""

Flush collected logs into response.

Argument ``add_header`` should be a function receiving two arguments:

``name`` and ``value`` of header.

"""

records = self._handler.get_records()

self._handler.clear_records()

republished = self._handler.get_republished()

self._handler.clear_republished()

for name, value in republished:

add_header(name, value)

logs = []

errors = []

for record in records:

try:

logs.append(self._prepare_log_record(record))

except Exception, e:

# this exception may be fired, because of buggy __repr__ or

# __str__ implementations on various objects

errors.append(self._handle_internal_exception(e))

chunks = self._encode(logs, errors, profile, extension_data)

guid = "%08x" % random.randint(0, 0xFFFFFFFF)

for i, chunk in enumerate(chunks):

add_header(CONST.FIRELOGGER_HEADER_FORMAT %

dict(guid=guid, identity=i), chunk)

def _prepare_log_record(self, record):

data = {

"level": self._log_level(record.levelno),

"message": self._handler.format(record),

"template": record.msg,

"timestamp": long(record.created * 1000 * 1000),

"time": (time.strftime("%H:%M:%S",

time.localtime(record.created)) +

(".%03d" % ((record.created - long(record.created)) * 1000))

)

}

props = ["args", "pathname", "lineno", "exc_text", "name", "process",

"thread", "threadName"]

for p in props:

try:

data[p] = getattr(record, p)

except AttributeError:

pass

try:

exc_info = getattr(record, 'exc_info')

if exc_info is not None:

data['exc_info'] = self._sanitize_exc_info(exc_info)

frames = []

t = exc_info[2]

while t:

try:

d = {}

for k,v in t.tb_frame.f_locals.iteritems():

if CONST.DEEP_LOCALS:

d[unicode(k)] = v

else:

d[unicode(k)] = repr(v)

frames.append(d)

except:

frames.append('?')

t = t.tb_next

data['exc_frames'] = frames

except AttributeError:

pass

return data

def _log_level(self, level):

if level >= logging.CRITICAL:

return "critical"

elif level >= logging.ERROR:

return "error"

elif level >= logging.WARNING:

return "warning"

elif level >= logging.INFO:

return "info"

else:

return "debug"

def _start(self):

self._handler.start()

def _finish(self):

self._handler.finish()

def _profile_wrap(self, func):

'''If the FIRELOGGER_RESPONSE_HEADER header has been passed with a

request, given function will be wrapped with a profile.

'''

if not self._profile_enabled:

return func

try:

import cProfile as profile

except ImportError:

import profile

self._prof = profile.Profile()

def prof_wrapper(*args, **kwargs):

return self._prof.runcall(func, *args, **kwargs)

return prof_wrapper

def _prepare_profile(self):

"""Prepares profiling information."""

if not self._profile_enabled or not hasattr(self, '_prof'):

return None

if not gprof2dot:

logging.warn('failed to import ``gprof2dot``, will not profile')

return None

self._prof.create_stats()

parser = gprof2dot.PstatsParser(self._prof)

def get_function_name((filename, line, name)):

module = os.path.splitext(filename)[0]

module_pieces = module.split(os.path.sep)

return "%s:%d:%s" % ("/".join(module_pieces[-4:]), line, name)

parser.get_function_name = get_function_name

output = StringIO()

gprof = parser.parse()

gprof.prune(0.005, 0.001)

# TODO: ^--- Parameterize node and edge thresholds.

dot = gprof2dot.DotWriter(output)

theme = gprof2dot.TEMPERATURE_COLORMAP

theme.bgcolor = (0.0, 0.0, 0.0)

# ^--- Use black text, for less eye-bleeding.

dot.graph(gprof, theme)

def get_info(self):

s = "Profile Graph:"

s += " %.3fs CPU" % self.total_tt

s += ": %d function calls" % self.total_calls

if self.total_calls != self.prim_calls:

s += " (%d primitive calls)" % self.prim_calls

return s

profile = {

"producer": "gprof2dot",

"producerVersion": str(gprof2dot.__version__),

"info": get_info(parser.stats),

"dot": output.getvalue(),

}

return profile

class FirePythonDjango(FirePythonBase):

"""

Django middleware to enable FirePython logging.

To use add 'firepython.middleware.FirePythonDjango' to your

MIDDLEWARE_CLASSES setting.

Optional settings:

- ``FIREPYTHON_PASSWORD``: password to protect your logs

- ``FIREPYTHON_LOGGER_NAME``: specific logger name you want to monitor

- ``FIREPYTHON_CHECK_AGENT``: set to False for prevent server to check

presence of firepython in user-agent HTTP header.

"""

def __init__(self):

from django.conf import settings

self._extension_data = {}

self._password = getattr(settings, 'FIREPYTHON_PASSWORD', None)

self._logger_name = getattr(settings, 'FIREPYTHON_LOGGER_NAME', None)

self._check_agent = getattr(settings, 'FIREPYTHON_CHECK_AGENT', True)

self.install_handler()

def __del__(self):

self.uninstall_handler()

def process_request(self, request):

if not self._check(request.META):

return

self._start()

# Make set_extension_data available via the request object.

if self._appstats_enabled:

request.firepython_appstats_enabled = True

request.firepython_set_extension_data = self._extension_data.__setitem__

def process_view(self, request, callback, callback_args, callback_kwargs):

args = (request, ) + callback_args

return self._profile_wrap(callback)(*args, **callback_kwargs)

def process_response(self, request, response):

check = self._check(request.META)

if self._client_message:

response.__setitem__(CONST.FIRELOGGER_MESSAGE_HEADER,

self._client_message)

if not check:

return response

profile = self._prepare_profile()

self._finish()

self._flush_records(response.__setitem__, profile, self._extension_data)

return response

def process_exception(self, request, exception):

if not self._check(request.META):

return

logging.exception(exception)

class FirePythonWSGI(FirePythonBase):

"""

WSGI middleware to enable FirePython logging.

Supply an application object and an optional password to enable password

protection. Also logger name may be specified.

"""

def __init__(self, app, password=None, logger_name=None, check_agent=True):

self.app = app

self._password = password

self._logger_name = logger_name

self._check_agent = check_agent

self.install_handler()

def __del__(self):

self.uninstall_handler()

def __call__(self, environ, start_response):

check = self._check(environ)

if not check and not self._client_message:

return self.app(environ, start_response) # a quick path

# firepython is enabled or we have a client message we want to communicate in headers

client_message = self._client_message

# asking why? see __ref_pymod_counter__

closure = ["200 OK", [], None]

extension_data = {} # Collect extension data here

sio = StringIO()

def faked_start_response(_status, _headers, _exc_info=None):

closure[0] = _status

closure[1] = _headers

closure[2] = _exc_info

if client_message:

closure[1].append(

(CONST.FIRELOGGER_MESSAGE_HEADER, client_message))

return sio.write

def add_header(name, value):

closure[1].append((name, value))

if self._appstats_enabled:

environ['firepython.appstats_enabled'] = True

if check:

self._start()

environ['firepython.set_extension_data'] = extension_data.__setitem__

# run app

try:

# the nested try-except block within

# a try-finally block is so that we stay

# python2.3 compatible

try:

app = self.app

if check:

app = self._profile_wrap(app)

app_iter = app(environ, faked_start_response)

output = list(app_iter)

except:

logging.warning("DeprecationWarning: raising a "

"string exception is deprecated")

logging.exception(sys.exc_info()[0])

raise

finally:

# Output the profile first, so we can see any errors in profiling.

if check:

profile = self._prepare_profile()

self._finish()

self._flush_records(add_header, profile, extension_data)

# start responding

write = start_response(*closure)

if sio.tell(): # position is not 0

sio.seek(0)

write(sio.read())

# return output

return output

def paste_filter_factory(global_conf, password_file='', logger_name='',

check_agent='true'):

from paste.deploy.converters import asbool

check_agent = asbool(check_agent)

get_password = lambda: ''

if password_file:

def get_password():

return open(password_file).read().strip()

def with_firepython_middleware(app):

return FirePythonWSGI(app, password=get_password(),

logger_name=logger_name,

check_agent=check_agent)

return with_firepython_middleware

__ref_pymod_counter__ = \

"http://jjinux.blogspot.com/2006/10/python-modifying-counter-in-closure.html"