Mercurial > kallithea
changeset 1186:b9ea10d3e419 beta
timperproxy will just measure the time of queries, and formatting will be handled by the new sql_formatter of queries from sqlalchemy itself. Updated ini files for new way logging
| author | Marcin Kuzminski <marcin@python-works.com> |
|---|---|
| date | Mon, 28 Mar 2011 22:13:21 +0200 |
| parents | 597bc7077f18 |
| children | 08d77411c881 |
| files | development.ini production.ini rhodecode/config/deployment.ini_tmpl rhodecode/lib/colored_formatter.py rhodecode/lib/timerproxy.py |
| diffstat | 5 files changed, 148 insertions(+), 100 deletions(-) [+] |
line wrap: on
line diff
--- a/development.ini Mon Mar 28 21:28:16 2011 +0200 +++ b/development.ini Mon Mar 28 22:13:21 2011 +0200 @@ -143,21 +143,21 @@ ######################################################### #sqlalchemy.db1.url = sqlite:///%(here)s/rhodecode.db sqlalchemy.db1.url = postgresql://postgres:qwe@localhost/rhodecode -#sqlalchemy.db1.echo = False -#sqlalchemy.db1.pool_recycle = 3600 +sqlalchemy.db1.echo = True +sqlalchemy.db1.pool_recycle = 3600 sqlalchemy.convert_unicode = true ################################ ### LOGGING CONFIGURATION #### ################################ [loggers] -keys = root, routes, rhodecode, sqlalchemy,beaker,templates +keys = root, routes, rhodecode, sqlalchemy, beaker, templates [handlers] -keys = console +keys = console, console_sql [formatters] -keys = generic,color_formatter +keys = generic, color_formatter, color_formatter_sql ############# ## LOGGERS ## @@ -168,32 +168,32 @@ [logger_routes] level = DEBUG -handlers = console +handlers = qualname = routes.middleware # "level = DEBUG" logs the route matched and routing variables. -propagate = 0 +propagate = 1 [logger_beaker] -level = ERROR -handlers = console +level = DEBUG +handlers = qualname = beaker.container -propagate = 0 +propagate = 1 [logger_templates] level = INFO -handlers = console +handlers = qualname = pylons.templating -propagate = 0 +propagate = 1 [logger_rhodecode] level = DEBUG -handlers = console +handlers = qualname = rhodecode -propagate = 0 +propagate = 1 [logger_sqlalchemy] -level = ERROR -handlers = console +level = INFO +handlers = console_sql qualname = sqlalchemy.engine propagate = 0 @@ -207,6 +207,12 @@ level = NOTSET formatter = color_formatter +[handler_console_sql] +class = StreamHandler +args = (sys.stderr,) +level = NOTSET +formatter = color_formatter_sql + ################ ## FORMATTERS ## ################ @@ -218,4 +224,9 @@ [formatter_color_formatter] class=rhodecode.lib.colored_formatter.ColorFormatter format= %(asctime)s.%(msecs)03d %(levelname)-5.5s [%(name)s] %(message)s +datefmt = %Y-%m-%d %H:%M:%S + +[formatter_color_formatter_sql] +class=rhodecode.lib.colored_formatter.ColorFormatterSql +format= %(asctime)s.%(msecs)03d %(levelname)-5.5s [%(name)s] %(message)s datefmt = %Y-%m-%d %H:%M:%S \ No newline at end of file
--- a/production.ini Mon Mar 28 21:28:16 2011 +0200 +++ b/production.ini Mon Mar 28 22:13:21 2011 +0200 @@ -29,7 +29,7 @@ threadpool_workers = 5 ##max request before thread respawn -threadpool_max_requests = 6 +threadpool_max_requests = 10 ##option to use threads of process use_threadpool = true @@ -41,13 +41,14 @@ [app:main] use = egg:rhodecode full_stack = true -static_files = false +static_files = true lang=en cache_dir = %(here)s/data index_dir = %(here)s/data/index +app_instance_uuid = prod1234 cut_off_limit = 256000 -force_https = false -commit_parse_limit = 25 +force_https = false +commit_parse_limit = 50 use_gravatar = true #################################### @@ -142,57 +143,57 @@ ######################################################### #sqlalchemy.db1.url = sqlite:///%(here)s/rhodecode.db sqlalchemy.db1.url = postgresql://postgres:qwe@localhost/rhodecode -#sqlalchemy.db1.echo = False -#sqlalchemy.db1.pool_recycle = 3600 +sqlalchemy.db1.echo = True +sqlalchemy.db1.pool_recycle = 3600 sqlalchemy.convert_unicode = true ################################ ### LOGGING CONFIGURATION #### ################################ [loggers] -keys = root, routes, rhodecode, sqlalchemy,beaker,templates +keys = root, routes, rhodecode, sqlalchemy, beaker, templates [handlers] -keys = console +keys = console, console_sql [formatters] -keys = generic,color_formatter +keys = generic, color_formatter, color_formatter_sql ############# ## LOGGERS ## ############# [logger_root] -level = INFO +level = NOTSET handlers = console [logger_routes] -level = INFO -handlers = console +level = DEBUG +handlers = qualname = routes.middleware # "level = DEBUG" logs the route matched and routing variables. -propagate = 0 +propagate = 1 [logger_beaker] -level = ERROR -handlers = console +level = DEBUG +handlers = qualname = beaker.container -propagate = 0 +propagate = 1 [logger_templates] level = INFO -handlers = console +handlers = qualname = pylons.templating -propagate = 0 +propagate = 1 [logger_rhodecode] level = DEBUG -handlers = console +handlers = qualname = rhodecode -propagate = 0 +propagate = 1 [logger_sqlalchemy] -level = ERROR -handlers = console +level = INFO +handlers = console_sql qualname = sqlalchemy.engine propagate = 0 @@ -203,9 +204,15 @@ [handler_console] class = StreamHandler args = (sys.stderr,) -level = NOTSET +level = INFO formatter = color_formatter +[handler_console_sql] +class = StreamHandler +args = (sys.stderr,) +level = WARN +formatter = color_formatter_sql + ################ ## FORMATTERS ## ################ @@ -217,4 +224,9 @@ [formatter_color_formatter] class=rhodecode.lib.colored_formatter.ColorFormatter format= %(asctime)s.%(msecs)03d %(levelname)-5.5s [%(name)s] %(message)s +datefmt = %Y-%m-%d %H:%M:%S + +[formatter_color_formatter_sql] +class=rhodecode.lib.colored_formatter.ColorFormatterSql +format= %(asctime)s.%(msecs)03d %(levelname)-5.5s [%(name)s] %(message)s datefmt = %Y-%m-%d %H:%M:%S \ No newline at end of file
--- a/rhodecode/config/deployment.ini_tmpl Mon Mar 28 21:28:16 2011 +0200 +++ b/rhodecode/config/deployment.ini_tmpl Mon Mar 28 22:13:21 2011 +0200 @@ -142,57 +142,57 @@ ### DB CONFIGS - EACH DB WILL HAVE IT'S OWN CONFIG ### ######################################################### sqlalchemy.db1.url = sqlite:///%(here)s/rhodecode.db -#sqlalchemy.db1.echo = False -#sqlalchemy.db1.pool_recycle = 3600 +sqlalchemy.db1.echo = True +sqlalchemy.db1.pool_recycle = 3600 sqlalchemy.convert_unicode = true ################################ ### LOGGING CONFIGURATION #### ################################ [loggers] -keys = root, routes, rhodecode, sqlalchemy,beaker,templates +keys = root, routes, rhodecode, sqlalchemy, beaker, templates [handlers] -keys = console +keys = console, console_sql [formatters] -keys = generic,color_formatter +keys = generic, color_formatter, color_formatter_sql ############# ## LOGGERS ## ############# [logger_root] -level = INFO +level = NOTSET handlers = console [logger_routes] -level = INFO -handlers = console +level = DEBUG +handlers = qualname = routes.middleware # "level = DEBUG" logs the route matched and routing variables. -propagate = 0 +propagate = 1 [logger_beaker] -level = ERROR -handlers = console +level = DEBUG +handlers = qualname = beaker.container -propagate = 0 +propagate = 1 [logger_templates] level = INFO -handlers = console +handlers = qualname = pylons.templating -propagate = 0 +propagate = 1 [logger_rhodecode] level = DEBUG -handlers = console +handlers = qualname = rhodecode -propagate = 0 +propagate = 1 [logger_sqlalchemy] -level = ERROR -handlers = console +level = INFO +handlers = console_sql qualname = sqlalchemy.engine propagate = 0 @@ -203,9 +203,15 @@ [handler_console] class = StreamHandler args = (sys.stderr,) -level = NOTSET +level = INFO formatter = color_formatter +[handler_console_sql] +class = StreamHandler +args = (sys.stderr,) +level = WARN +formatter = color_formatter_sql + ################ ## FORMATTERS ## ################ @@ -217,4 +223,9 @@ [formatter_color_formatter] class=rhodecode.lib.colored_formatter.ColorFormatter format= %(asctime)s.%(msecs)03d %(levelname)-5.5s [%(name)s] %(message)s +datefmt = %Y-%m-%d %H:%M:%S + +[formatter_color_formatter_sql] +class=rhodecode.lib.colored_formatter.ColorFormatterSql +format= %(asctime)s.%(msecs)03d %(levelname)-5.5s [%(name)s] %(message)s datefmt = %Y-%m-%d %H:%M:%S \ No newline at end of file
--- a/rhodecode/lib/colored_formatter.py Mon Mar 28 21:28:16 2011 +0200 +++ b/rhodecode/lib/colored_formatter.py Mon Mar 28 22:13:21 2011 +0200 @@ -14,8 +14,35 @@ 'WARNING': CYAN, # level 30 'INFO': GREEN, # level 20 'DEBUG': BLUE, # level 10 + 'SQL' : YELLOW } +def one_space_trim(s): + if s.find(" ") == -1: + return s + else: + s = s.replace(' ', ' ') + return one_space_trim(s) + +def format_sql(sql): + sql = sql.replace('\n', '') + sql = one_space_trim(sql) + sql = sql\ + .replace(',', ',\n\t')\ + .replace('SELECT', '\n\tSELECT \n\t')\ + .replace('UPDATE', '\n\tUPDATE \n\t')\ + .replace('DELETE', '\n\tDELETE \n\t')\ + .replace('FROM', '\n\tFROM')\ + .replace('ORDER BY', '\n\tORDER BY')\ + .replace('LIMIT', '\n\tLIMIT')\ + .replace('WHERE', '\n\tWHERE')\ + .replace('AND', '\n\tAND')\ + .replace('LEFT', '\n\tLEFT')\ + .replace('INNER', '\n\tINNER')\ + .replace('INSERT', '\n\tINSERT')\ + .replace('DELETE', '\n\tDELETE') + return sql + class ColorFormatter(logging.Formatter): def __init__(self, *args, **kwargs): @@ -26,13 +53,31 @@ """ Changes record's levelname to use with COLORS enum """ - + levelname = record.levelname start = COLOR_SEQ % (COLORS[levelname]) def_record = logging.Formatter.format(self, record) end = RESET_SEQ - + colored_record = start + def_record + end return colored_record -logging.ColorFormatter = ColorFormatter + +class ColorFormatterSql(logging.Formatter): + + def __init__(self, *args, **kwargs): + # can't do super(...) here because Formatter is an old school class + logging.Formatter.__init__(self, *args, **kwargs) + + def format(self, record): + """ + Changes record's levelname to use with COLORS enum + """ + + start = COLOR_SEQ % (COLORS['SQL']) + def_record = format_sql(logging.Formatter.format(self, record)) + end = RESET_SEQ + + colored_record = start + def_record + end + return colored_record +
--- a/rhodecode/lib/timerproxy.py Mon Mar 28 21:28:16 2011 +0200 +++ b/rhodecode/lib/timerproxy.py Mon Mar 28 22:13:21 2011 +0200 @@ -7,53 +7,22 @@ COLOR_SEQ = "\033[1;%dm" COLOR_SQL = YELLOW normal = '\x1b[0m' - return COLOR_SEQ % COLOR_SQL + sql + normal - -def one_space_trim(s): - if s.find(" ") == -1: - return s - else: - s = s.replace(' ', ' ') - return one_space_trim(s) - -def format_sql(sql): - sql = color_sql(sql) - sql = sql.replace('\n', '') - sql = one_space_trim(sql) - sql = sql\ - .replace(',', ',\n\t')\ - .replace('SELECT', '\n\tSELECT \n\t')\ - .replace('UPDATE', '\n\tUPDATE \n\t')\ - .replace('DELETE', '\n\tDELETE \n\t')\ - .replace('FROM', '\n\tFROM')\ - .replace('ORDER BY', '\n\tORDER BY')\ - .replace('LIMIT', '\n\tLIMIT')\ - .replace('WHERE', '\n\tWHERE')\ - .replace('AND', '\n\tAND')\ - .replace('LEFT', '\n\tLEFT')\ - .replace('INNER', '\n\tINNER')\ - .replace('INSERT', '\n\tINSERT')\ - .replace('DELETE', '\n\tDELETE') - return sql - + return COLOR_SEQ % COLOR_SQL + sql + normal class TimerProxy(ConnectionProxy): - + def __init__(self): super(TimerProxy, self).__init__() self.logging_name = 'timerProxy' self.log = log.instance_logger(self, True) - - def cursor_execute(self, execute, cursor, statement, parameters, context, executemany): - + + def cursor_execute(self, execute, cursor, statement, parameters, + context, executemany): + now = time.time() try: - self.log.info(">>>>> STARTING QUERY >>>>>") + self.log.info(color_sql(">>>>> STARTING QUERY >>>>>")) return execute(cursor, statement, parameters, context) finally: total = time.time() - now - try: - self.log.info(format_sql("Query: %s" % statement % parameters)) - except TypeError: - self.log.info(format_sql("Query: %s %s" % (statement, parameters))) - self.log.info("<<<<< TOTAL TIME: %f <<<<<" % total) + self.log.info(color_sql("<<<<< TOTAL TIME: %f <<<<<" % total))