Author: justi9 Date: 2010-09-21 15:47:32 -0400 (Tue, 21 Sep 2010) New Revision: 4321 Modified: mgmt/newdata/cumin/bin/cumin-bench mgmt/newdata/cumin/python/cumin/widgets.py mgmt/newdata/wooly/python/wooly/__init__.py mgmt/newdata/wooly/python/wooly/bench.py mgmt/newdata/wooly/python/wooly/pages.py mgmt/newdata/wooly/python/wooly/server.py Log: This is a half-way step to bz 622506 and an attempt to address 635881. * Support page-rendered error output * Remove PageForbidden; it's handled in normal page execution context * Don't parse cookies twice on every request * Enhance http-level logging * Move ClientSession with the server code * Bring cumin-bench back to life for testing Modified: mgmt/newdata/cumin/bin/cumin-bench =================================================================== --- mgmt/newdata/cumin/bin/cumin-bench 2010-09-21 19:01:38 UTC (rev 4320) +++ mgmt/newdata/cumin/bin/cumin-bench 2010-09-21 19:47:32 UTC (rev 4321) @@ -2,11 +2,44 @@ import sys -from cumin.tools import CuminBenchTool +from wooly.bench import BenchmarkHarness +from cumin import Cumin +from cumin.config import * + def do_main(): - CuminBenchTool("cumin-bench").main() + config = CuminConfig() + values = config.parse() + parser = CuminOptionParser(values.web) + + opts, args = parser.parse_args() + + setup_logging(opts) + + broker_uris = [x.strip() for x in opts.brokers.split(",")] + + cumin = Cumin(config.home, broker_uris, opts.database) + + cumin.debug = True + cumin.user = values.web.user + cumin.update_interval = values.web.update_interval + + cumin.check() + cumin.init() + + cumin.session.start() + + harness = BenchmarkHarness(cumin) + harness.continue_on_error = True + harness.check_output = False + harness.print_output = False + + try: + harness.run(1000) + finally: + cumin.stop() + def main(): if "--profile" in sys.argv: from profile import Profile Modified: mgmt/newdata/cumin/python/cumin/widgets.py =================================================================== --- mgmt/newdata/cumin/python/cumin/widgets.py 2010-09-21 19:01:38 UTC (rev 4320) +++ mgmt/newdata/cumin/python/cumin/widgets.py 2010-09-21 19:47:32 UTC (rev 4321) @@ -1336,9 +1336,20 @@ self.user = UserAttribute(app, "user") self.add_attribute(self.user) + def service(self, session): + conn = self.app.database.get_connection() + session.cursor = conn.cursor() + + try: + return super(CuminPage, self).service(session) + except PageRedirect: + raise + except: + conn.rollback() + + raise + def do_process(self, session): - session.cursor = self.get_cursor(session) - if not self.authorized(session): page = self.app.login_page @@ -1351,17 +1362,6 @@ super(CuminPage, self).do_process(session) - def get_cursor(self, session): - try: - cursor = session.client_session.attributes["read_cursor"] - except KeyError: - conn = self.app.database.get_connection() - cursor = conn.cursor() - - session.client_session.attributes["read_cursor"] = cursor - - return cursor - def authorized(self, session): if not self.protected: return True Modified: mgmt/newdata/wooly/python/wooly/__init__.py =================================================================== --- mgmt/newdata/wooly/python/wooly/__init__.py 2010-09-21 19:01:38 UTC (rev 4320) +++ mgmt/newdata/wooly/python/wooly/__init__.py 2010-09-21 19:47:32 UTC (rev 4321) @@ -401,6 +401,9 @@ self.redirect = Attribute(app, "redirect") self.add_attribute(self.redirect) + self.error = Attribute(app, "error") + self.add_attribute(self.error) + self.profile = self.ProfileAttribute(app, "profile") self.add_attribute(self.profile) @@ -442,7 +445,7 @@ return self.page_parameters def get_last_modified(self, session): - return datetime.utcnow() + return None def get_content_type(self, session): raise Exception("Not implemented") @@ -465,26 +468,105 @@ redirect = self.redirect.get(session) if redirect: - raise PageRedirect(redirect) + raise PageRedirect() return self.render(session) + def service_error(self, session): + self.error.set(session, PageError(self, session)) + + return self.render(session) + def render_id(self, session, *args): return self.name + def render_content(self, session): + if self.error.get(session): + return self.render_error(session) + + return super(Page, self).render_content(session) + + def render_error(self, session): + return self.error.get(session).render() + class ProfileAttribute(Attribute): def get_default(self, session): return PageProfile(self) class PageRedirect(Exception): - def __init__(self, url): - Exception.__init__(self) + pass - self.url = url +class PageError(object): + def __init__(self, page, session): + self.page = page + self.session = session -class PageForbidden(Exception): - pass + def render(self): + writer = Writer() + writer.write("APPLICATION ERROR\n\n") + print_exc(None, writer) + + writer.write("\n") + + profile = self.page.profile.get(self.session) + + if profile: + writer.write("Widget trace:\n\n") + profile.print_stack_trace(writer) + writer.write("\n") + + self.print_messages(writer) + self.print_session(writer) + + env = self.session.request_environment + + if env: + self.print_url_vars(env["QUERY_STRING"], writer) + self.print_environment(env, writer) + + return "<pre><![CDATA[%s]]></pre>" % writer.to_string() + + def print_messages(self, writer): + writer.write("Messages:\n\n") + + for message in self.session.messages: + writer.write(" %s\n" % message) + + writer.write("\n") + + def print_session(self, writer): + writer.write("Session:\n\n") + + for path in sorted(self.session.values_by_path): + value = self.session.values_by_path[path] + + writer.write(" %-30s %s\n" % (path, value)) + + writer.write("\n") + + def print_url_vars(self, query, writer): + writer.write("URL variables:\n\n") + + if query: + vars = query.split(";") + + for var in sorted(vars): + key, value = var.split("=") + writer.write(" %-30s %s\n" % (key, value)) + + writer.write("\n") + + def print_environment(self, env, writer): + writer.write("Environment:\n\n") + + for key in sorted(env): + value = env[key] + + writer.write(" %-30s %s\n" % (key, value)) + + writer.write("\n") + from parameters import DictParameter class Application(object): @@ -544,8 +626,9 @@ self.values_by_path = dict() self.cookies_by_name = dict() # name => (newly set?, value, expires) - self.headers_by_name = dict() + self.request_environment = None + self.messages = list() def branch(self): @@ -750,12 +833,4 @@ def set(self, session, value): session.set(self.key, value) -class ClientSession(object): - def __init__(self): - self.id = unique_id() - self.created = datetime.now() - self.visited = None - - self.attributes = dict() - from pages import ResourcePage Modified: mgmt/newdata/wooly/python/wooly/bench.py =================================================================== --- mgmt/newdata/wooly/python/wooly/bench.py 2010-09-21 19:01:38 UTC (rev 4320) +++ mgmt/newdata/wooly/python/wooly/bench.py 2010-09-21 19:47:32 UTC (rev 4321) @@ -1,6 +1,7 @@ from xml.parsers.expat import ParserCreate -from wooly import Session, ClientSession +from wooly import Session, PageRedirect +from wooly.server import ClientSession from util import * class BenchmarkHarness(object): @@ -10,7 +11,6 @@ self.check_output = False self.print_output = False - from wooly import ClientSession, Session self.client_session = ClientSession() self.profiles = list() @@ -28,41 +28,41 @@ self.profiles.append(profile) try: - page.process(session) - + content = page.service(session) + passed = True + except PageRedirect: redirect = page.redirect.get(session) - if redirect: - return self.visit(redirect, url, depth + 1) + assert redirect - html = page.render(session) - - if self.print_output: - self.print_output_with_line_numbers(html) - - if self.check_output: - parser = ParserCreate() - parser.Parse(html) + return self.visit(redirect, url, depth + 1) except KeyboardInterrupt: raise except: print "Page failure" + content = "" + passed = False + profile.print_stack_trace() print "Referer: %s" % referer - if self.continue_on_error: - html = "" - print_exc(file=sys.stderr) - else: + if not self.continue_on_error: raise - return (html, profile) + if self.print_output: + self.print_output_with_line_numbers(content) - def print_output_with_line_numbers(self, html): - lines = html.split(os.linesep) + if self.check_output: + parser = ParserCreate() + parser.Parse(content) + return (content, profile, passed) + + def print_output_with_line_numbers(self, content): + lines = content.split(os.linesep) + print "-" * 80 for i, line in enumerate(lines): @@ -75,6 +75,9 @@ visited = set() times = list() + passed = 0 + failed = 0 + count = 1 referer = None url = "" @@ -86,19 +89,23 @@ start = time.time() - html, profile = self.visit(url, referer, 0) + content, profile, okay = self.visit(url, referer, 0) end = time.time() - bytes = len(html) + if okay: + passed += 1 + else: + failed += 1 + + bytes = len(content) millis = (end - start) * 1000 print "%i [%i bytes, %i millis]" % (count, bytes, millis) times.append(millis) - profile.print_process_render_asymmetry() - + #profile.print_process_render_asymmetry() #profile.compute_times() #profile.print_results() #profile.print_process_calls() @@ -118,12 +125,17 @@ url, referer = urls.pop() - self.print_profile() + print + print "Passed: %i" % passed + print "Failed: %i" % failed - args = (min(times), max(times), sum(times) / float(len(times))) + args = (sum(times) / float(len(times)), min(times), max(times)) - print "[min %.3f, max %.3f, avg %.3f]" % args + print "Times: Avg %.3f, Min %.3f, Max %.3f" % args + print + self.print_profile() + def print_profile(self): render_times_by_widget = defaultdict(list) @@ -131,11 +143,12 @@ profile.compute_times() profile.collate_render_times(render_times_by_widget) - row = "%-120s %8.3f %8.3f %8.3f %8i %8.3f" + head = "%-110s %8s %8s %8s %8s %8s" - print "-" * 80 - #print row % ("Class", "Min", "Max", "Avg", "Count", "Total") + print head % ("Widget", "Avg", "Min", "Max", "Count", "Total") + row = "%-110s %8.3f %8.3f %8.3f %8i %8.3f" + records = list() for widget in render_times_by_widget: @@ -145,11 +158,14 @@ total = sum(times) avg = total / float(count) - records.append((widget, min(times), max(times), avg, count, total)) + records.append((widget, avg, min(times), max(times), count, total)) - for record in sorted_by_index(records, 5): + for i, record in enumerate(reversed(sorted_by_index(records, 5))): print row % record + if i == 25: + break + def truncate(string, length): if len(string) > length: return string[:length] Modified: mgmt/newdata/wooly/python/wooly/pages.py =================================================================== --- mgmt/newdata/wooly/python/wooly/pages.py 2010-09-21 19:01:38 UTC (rev 4320) +++ mgmt/newdata/wooly/python/wooly/pages.py 2010-09-21 19:47:32 UTC (rev 4321) @@ -108,7 +108,7 @@ self.app.add_page(self.javascript_page) def get_content_type(self, session): - value = session.headers_by_name.get("user_agent") + value = session.request_environment.get("HTTP_USER_AGENT") if value and value.find("MSIE 6") != -1: content_type = self.html_content_type Modified: mgmt/newdata/wooly/python/wooly/server.py =================================================================== --- mgmt/newdata/wooly/python/wooly/server.py 2010-09-21 19:01:38 UTC (rev 4320) +++ mgmt/newdata/wooly/python/wooly/server.py 2010-09-21 19:47:32 UTC (rev 4321) @@ -62,73 +62,94 @@ return self.app.pages_by_name.get(name) - # XXX Now we're parsing cookies twice - def get_client_session(self, env, headers): - string = env.get("HTTP_COOKIE") - cookies_by_name = dict() - - if string: - for crumb in string.split(";"): - name, value = crumb.split("=", 1) - cookies_by_name[name.strip()] = value.strip() - + def get_last_requested(self, env): try: - session_id = cookies_by_name["session"] - session = self.client_sessions_by_id[session_id] + ims = env["HTTP_IF_MODIFIED_SINCE"] except KeyError: - session = ClientSession() - self.client_sessions_by_id[session.id] = session - headers.append(("Set-Cookie", "session=%s" % session.id)) + return None + + try: + then = datetime(*time.strptime(str(ims), self.http_date)[0:6]) + except AttributeError: + return None - session.visited = datetime.now() + return then - return session - def service_request(self, env, response): - log.info("Servicing %s %s", env["REQUEST_METHOD"], env["REQUEST_URI"]) + log.info("Request %s %s", env["REQUEST_METHOD"], env["REQUEST_URI"]) - headers = list() - page = self.get_page(env) - if not page: - return self.send_not_found(response, headers) + if page: + status, headers, content = self.service_page_request(page, env) + else: + status = "404 Not Found" + headers = () + content = "" - session = Session(page) - session.client_session = self.get_client_session(env, headers) + response(status, headers) - ims = env.get("HTTP_IF_MODIFIED_SINCE") + log.info("Response %s", status) - if ims: - modified = page.get_last_modified(session).replace(microsecond=0) + log.debug("Response headers:") - try: - since = datetime(*time.strptime(str(ims), self.http_date)[0:6]) + for header in headers: + log.debug(" %-24s %s", *header) - if modified <= since: - return self.send_not_modified(response, headers) - except AttributeError: - log.error("If-modified-since check failed; ims=%s" % str(ims)) + return (content,) + # XXX consider moving this closer to Page or a WsgiPageAdapter + def service_page_request(self, page, env): + session = Session(page) + self.adapt_request_to_session(env, session) - try: - content = page.service(session) - except PageRedirect, e: - return self.send_redirect(response, headers, e.url) - except PageForbidden: - return self.send_forbidden(response, headers) - except: - return self.send_error(response, headers, env, page, session) + #log.debug("Using %s, %s", page, session.client_session) - headers.append(("Content-Length", str(len(content)))) + status = None + headers = list() + content = "" - self.adapt_session_to_response(page, session, headers) + last_modified = page.get_last_modified(session) + last_requested = self.get_last_requested(env) - response("200 OK", headers) + if last_modified: + last_modified = last_modified.replace(microsecond=0) - return (content,) + value = last_modified.strftime(self.http_date_gmt) + headers.append(("Last-Modified", value)) + if last_modified is None or last_requested is None \ + or last_modified > last_requested: + try: + content = page.service(session) + status = "200 OK" + except PageRedirect: + status = "303 See Other" + headers.append(("Location", page.redirect.get(session))) + except: + content = page.service_error(session) + status = "500 Internal Error" + else: + status = "304 Not Modified" + + if content: + content_length = str(len(content)) + content_type = page.get_content_type(session) + + headers.append(("Content-Length", content_length)) + headers.append(("Content-Type", content_type)) + + cache = page.get_cache_control(session) + + if cache: + headers.append(("Cache-Control", cache)) + + for header in session.marshal_cookies(): + headers.append(("Set-Cookie", header)) + + return status, headers, content + def adapt_request_to_session(self, env, session): session.unmarshal_url_vars(env["QUERY_STRING"]) @@ -150,126 +171,24 @@ except KeyError: pass - for key, value in env.iteritems(): - if key.startswith("HTTP_"): - name = key[5:].lower() - session.headers_by_name[name] = value + session.request_environment = env + session.client_session = self.get_client_session(session) - def adapt_session_to_response(self, page, session, headers): - last_modified = page.get_last_modified(session) + def get_client_session(self, session): + try: + csession_id = session.cookies_by_name["session"][1] + csession = self.client_sessions_by_id[csession_id] + except KeyError: + csession = ClientSession() + self.client_sessions_by_id[csession.id] = csession + session.set_cookie("session", csession.id) - if last_modified: - when = last_modified.strftime(self.http_date_gmt) - headers.append(("Last-Modified", when)) + log.debug("Created %s", csession) - content_type = page.get_content_type(session) + csession.visited = datetime.now() - if content_type: - headers.append(("Content-Type", content_type)) + return csession - cache = page.get_cache_control(session) - - if cache: - headers.append(("Cache-Control", cache)) - - for header in session.marshal_cookies(): - headers.append(("Set-Cookie", header)) - - def send_message(self, response, headers, message): - headers.append(("Content-Length", str(len(message)))) - headers.append(("Content-Type", "text/plain")) - - response(message, headers) - - return (message,) - - def send_not_found(self, response, headers): - return self.send_message(response, headers, "404 Not Found") - - def send_forbidden(self, response, headers): - return self.send_message(response, headers, "403 Forbidden") - - def send_redirect(self, response, headers, url): - headers.append(("Location", url)) - headers.append(("Content-Length", "0")) - - response("303 See Other", headers) - - return () - - def send_not_modified(self, response, headers): - headers.append(("Content-Length", "0")) - - response("304 Not Modified", headers) - - return () - - def send_error(self, response, headers, env, page, session): - headers.append(("Content-Type", "text/plain")) - - response("500 Internal Error", headers) - - writer = Writer() - writer.write("APPLICATION ERROR\n\n") - - print_exc(None, writer) - - writer.write("\n") - - profile = page.profile.get(session) - - if profile: - writer.write("Widget trace:\n\n") - profile.print_stack_trace(writer) - writer.write("\n") - - self.print_messages(session, writer) - self.print_session(session, writer) - self.print_url_vars(env["QUERY_STRING"], writer) - self.print_environment(env, writer) - - return writer.to_string() - - def print_messages(self, session, writer): - writer.write("Messages:\n\n") - - for message in session.messages: - writer.write(" %s\n" % message) - - writer.write("\n") - - def print_session(self, session, writer): - writer.write("Session:\n\n") - - for path in sorted(session.values_by_path): - value = session.values_by_path[path] - - writer.write(" %-30s %s\n" % (path, value)) - - writer.write("\n") - - def print_url_vars(self, query, writer): - writer.write("URL variables:\n\n") - - if query: - vars = query.split(";") - - for var in sorted(vars): - key, value = var.split("=") - writer.write(" %-30s %s\n" % (key, value)) - - writer.write("\n") - - def print_environment(self, env, writer): - writer.write("Environment:\n\n") - - for key in sorted(env): - value = env[key] - - writer.write(" %-30s %s\n" % (key, value)) - - writer.write("\n") - def __repr__(self): return "%s(%s,%i)" % (self.__class__.__name__, self.host, self.port) @@ -292,6 +211,18 @@ def stop(self): self.wsgi_server.stop() +class ClientSession(object): + def __init__(self): + self.id = unique_id() + self.created = datetime.now() + self.visited = None + + self.attributes = dict() + + def __repr__(self): + args = (self.__class__.__name__, self.id, self.created) + return "%s(%s,%s)" % args + class ClientSessionExpireThread(Thread): def __init__(self, server): super(ClientSessionExpireThread, self).__init__()