From c4befed541df2434fa1c67d9d061010ea80f1e12 Mon Sep 17 00:00:00 2001 From: AliBsk Date: Fri, 1 Sep 2023 22:16:27 +0300 Subject: [PATCH 1/6] sa logging minor improvements --- py4web/server_adapters.py | 148 +++++++++++++++++++++++++++++--------- 1 file changed, 114 insertions(+), 34 deletions(-) diff --git a/py4web/server_adapters.py b/py4web/server_adapters.py index 1b0953054..824d62133 100644 --- a/py4web/server_adapters.py +++ b/py4web/server_adapters.py @@ -1,5 +1,6 @@ import logging import os +import sys import ssl from ombott.server_adapters import ServerAdapter @@ -16,6 +17,16 @@ "rocketServer", ] + wsservers_list +# ---------------------- utils ----------------------------------------------- + +# export PY4WEB_LOGS=/tmp # export PY4WEB_LOGS= +def get_log_file(): + LOG_DIR = os.environ.get("PY4WEB_LOGS", None) + LOG_FILE = os.path.join (LOG_DIR, 'server-py4web.log') if LOG_DIR else None + if LOG_FILE: + print(f"log_file: {LOG_FILE}") + return LOG_FILE + def check_level(level): @@ -44,26 +55,46 @@ def check_level(level): ) -def logging_conf(level, log_file="server-py4web.log"): +def logging_conf(level=logging.WARN, logger_name=__name__): - # export PY4WEB_LOGS=/tmp # set log_file directory + LOG_FILE = get_log_file() + log_to = dict() - log_dir = os.environ.get("PY4WEB_LOGS", None) + if LOG_FILE: - log_param = { - "format":"%(threadName)s | %(message)s", - "level":check_level(level), - } - - if log_dir: - h = logging.FileHandler( - os.path.join( log_dir, log_file), + if sys.version_info >= (3, 9): + log_to["filename" ] = LOG_FILE + log_to["filemode" ] = "w" + log_to["encoding"] = "utf-8" + else: # sys.version_info < (3, 9) + + h = logging.FileHandler( + LOG_FILE, mode = "w", encoding = "utf-8" ) - log_param.update( {"handlers": [h]} ) + log_to.update( {"handlers": [h]} ) + - logging.basicConfig(**log_param) + short_msg = "%(message)s > %(threadName)s > %(asctime)s.%(msecs)03d" + #long_msg = short_msg + " > %(funcName)s > %(filename)s:%(lineno)d > %(levelname)s" + + time_msg = '%H:%M:%S' + #date_time_msg = '%Y-%m-%d %H:%M:%S' + logging.basicConfig( + format=short_msg, + datefmt=time_msg, + level=check_level(level), + **log_to, + ) + + logger_name = "SA:" + logger_name + log = logging.getLogger(logger_name) + log.propagate = True + log.info( f'info start logger {logger_name}' ) + log.warn( f'warn start logger {logger_name}' ) + log.debug( f'debug start logger {logger_name}' ) + return log def get_workers(opts, default=10): @@ -72,9 +103,10 @@ def get_workers(opts, default=10): except KeyError: return default +# ---------------------- servers ----------------------------------------------- def gevent(): - # gevent version 22.10.2 + # gevent version 23.7.0 import threading @@ -91,22 +123,21 @@ def gevent(): class GeventServer(ServerAdapter): def run(self, handler): + LOG_FILE = get_log_file() - logger = "default" # not None - from gevent doc - if not self.quiet: + logger = "default" - logger = logging.getLogger("gevent") - log_dir = os.environ.get("PY4WEB_LOGS", None) + if not self.quiet: + logger = logging.getLogger("SA:gevent") fh = ( - logging.FileHandler(None) - if not log_dir - else ( - logging.FileHandler(os.path.join(log_dir, "server-py4web.log")) - ) + logging.FileHandler() + if not LOG_FILE + else logging.FileHandler(LOG_FILE, mode='w') ) logger.setLevel(check_level(self.options["logging_level"])) logger.addHandler(fh) - logger.addHandler(logging.StreamHandler()) + #logger.addHandler(logging.StreamHandler()) + logger.propagate = True certfile = self.options.get("certfile", None) @@ -154,12 +185,13 @@ def geventWebSocketServer(): class GeventWebSocketServer(ServerAdapter): def run(self, handler): - logger = "default" # not None !! from gevent doc + logger = "default" + if not self.quiet: - logging_conf( - self.options["logging_level"], + logger = logging_conf( + self.options["logging_level"], "gevent-ws", ) - logger = logging.getLogger("gevent-ws") + certfile = self.options.get("certfile", None) @@ -198,11 +230,9 @@ class WSGIRefThreadingServer(ServerAdapter): def run(self, app): if not self.quiet: - - logging_conf( - self.options["logging_level"], + self.log = logging_conf( + self.options["logging_level"], "wsgiref", ) - self.log = logging.getLogger("WSGIRef") self_run = self # used in internal classes to access options and logger @@ -277,7 +307,7 @@ def log_message(self, format, *args): ) self_run.log.info(msg) - handler_cls = self.options.get("handler_class", LogHandler) + #handler_cls = self.options.get("handler_class", LogHandler) server_cls = Server if ":" in self.host: # Fix wsgiref for IPv6 addresses. @@ -288,7 +318,7 @@ class ServerClass(Server): server_cls = ServerClass - srv = make_server(self.host, self.port, app, server_cls, handler_cls) + srv = make_server(self.host, self.port, app, server_cls, LogHandler ) # handler_cls) srv.serve_forever() return WSGIRefThreadingServer @@ -327,3 +357,53 @@ def run(self, app): server.start() return RocketServer + + +""" +# how to write to server-adapters.log from controllers.py +# cp -a _scaffold test-salog + +import sys +import logging +from .common import logger +from .settings import APP_NAME +from threading import Lock + + +_sa_lock = Lock() +_srv_log=None +def log_info(mess, dbg=True, ): + def salog(pat='SA:'): + global _srv_log, _sa_lock + if _srv_log: # and isinstance( _srv_log, logging.Logger ): + return _srv_log + hs= [e for e in logging.root.manager.loggerDict if e.startswith(pat) ] + if len(hs) == 0: + return logger + + _sa_lock.acquire() + _srv_log = logging.getLogger(hs[0]) + _sa_lock.release() + + return _srv_log + + dbg and salog().info(str(mess)) + +log_warn=log_info +log_debug=log_info + +log_warn('0'* 30 + ' ' +APP_NAME) + +@action("index") +@action.uses("index.html", auth, T) +def index(): + + log_warn('7'* 30 + ' ' +APP_NAME) + log_info('9'* 30 + ' ' +APP_NAME) + + user = auth.get_user() + message = T("Hello {first_name}").format(**user) if user else T("Hello") + actions = {"allowed_actions": auth.param.allowed_actions} + return dict(message=message, actions=actions) + +""" From 670e59f77ecb9af0d318e10689b4cfb929c89739 Mon Sep 17 00:00:00 2001 From: AliBsk Date: Tue, 12 Sep 2023 08:44:34 +0300 Subject: [PATCH 2/6] sa, renaming variables --- py4web/server_adapters.py | 60 +++++++++++++++++++++------------------ 1 file changed, 32 insertions(+), 28 deletions(-) diff --git a/py4web/server_adapters.py b/py4web/server_adapters.py index 824d62133..21f2b872c 100644 --- a/py4web/server_adapters.py +++ b/py4web/server_adapters.py @@ -21,11 +21,11 @@ # export PY4WEB_LOGS=/tmp # export PY4WEB_LOGS= def get_log_file(): - LOG_DIR = os.environ.get("PY4WEB_LOGS", None) - LOG_FILE = os.path.join (LOG_DIR, 'server-py4web.log') if LOG_DIR else None - if LOG_FILE: - print(f"log_file: {LOG_FILE}") - return LOG_FILE + log_dir = os.environ.get("PY4WEB_LOGS", None) + log_file = os.path.join (log_dir, 'server-py4web.log') if log_dir else None + if log_file: + print(f"log_file: {log_file}") + return log_file def check_level(level): @@ -57,30 +57,31 @@ def check_level(level): def logging_conf(level=logging.WARN, logger_name=__name__): - LOG_FILE = get_log_file() + log_file = get_log_file() log_to = dict() - if LOG_FILE: + if log_file: if sys.version_info >= (3, 9): - log_to["filename" ] = LOG_FILE + log_to["filename" ] = log_file log_to["filemode" ] = "w" log_to["encoding"] = "utf-8" + else: # sys.version_info < (3, 9) h = logging.FileHandler( - LOG_FILE, + log_file, mode = "w", encoding = "utf-8" ) log_to.update( {"handlers": [h]} ) - short_msg = "%(message)s > %(threadName)s > %(asctime)s.%(msecs)03d" #long_msg = short_msg + " > %(funcName)s > %(filename)s:%(lineno)d > %(levelname)s" time_msg = '%H:%M:%S' #date_time_msg = '%Y-%m-%d %H:%M:%S' + logging.basicConfig( format=short_msg, datefmt=time_msg, @@ -88,6 +89,9 @@ def logging_conf(level=logging.WARN, logger_name=__name__): **log_to, ) + if logger_name is None: + return None + logger_name = "SA:" + logger_name log = logging.getLogger(logger_name) log.propagate = True @@ -109,7 +113,6 @@ def gevent(): # gevent version 23.7.0 import threading - from gevent import local, pywsgi # pip install gevent if not isinstance(threading.local(), local.local): @@ -122,8 +125,8 @@ def gevent(): # ./py4web.py run apps -s gevent --watch=off --host=192.168.1.161 --port=8443 --ssl_cert=server.pem -L 0 class GeventServer(ServerAdapter): - def run(self, handler): - LOG_FILE = get_log_file() + def run(self, app_handler): + log_file = get_log_file() logger = "default" @@ -131,8 +134,8 @@ def run(self, handler): logger = logging.getLogger("SA:gevent") fh = ( logging.FileHandler() - if not LOG_FILE - else logging.FileHandler(LOG_FILE, mode='w') + if not log_file + else logging.FileHandler(log_file, mode='w') ) logger.setLevel(check_level(self.options["logging_level"])) logger.addHandler(fh) @@ -155,7 +158,7 @@ def run(self, handler): server = pywsgi.WSGIServer( (self.host, self.port), - handler, + app_handler, log=logger, error_log=logger, **ssl_args @@ -184,7 +187,7 @@ def geventWebSocketServer(): # -sSv https://192.168.1.161:9000/ class GeventWebSocketServer(ServerAdapter): - def run(self, handler): + def run(self, app_handler): logger = "default" if not self.quiet: @@ -206,7 +209,7 @@ def run(self, handler): server = pywsgi.WSGIServer( (self.host, self.port), - handler, + app_handler, handler_class=WebSocketHandler, log=logger, error_log=logger, @@ -227,7 +230,9 @@ def wsgirefThreadingServer(): from wsgiref.simple_server import WSGIRequestHandler, WSGIServer, make_server class WSGIRefThreadingServer(ServerAdapter): - def run(self, app): + def run(self, app_handler): + + self.log = None if not self.quiet: self.log = logging_conf( @@ -318,7 +323,7 @@ class ServerClass(Server): server_cls = ServerClass - srv = make_server(self.host, self.port, app, server_cls, LogHandler ) # handler_cls) + srv = make_server(self.host, self.port, app_handler, server_cls, LogHandler ) # handler_cls) srv.serve_forever() return WSGIRefThreadingServer @@ -331,7 +336,7 @@ def rocketServer(): from .rocket3 import Rocket3 as Rocket class RocketServer(ServerAdapter): - def run(self, app): + def run(self, app_handler): if not self.quiet: @@ -353,7 +358,7 @@ def run(self, app): else (self.host, self.port) ) - server = Rocket(interface, "wsgi", dict(wsgi_app=app)) + server = Rocket(interface, "wsgi", dict(wsgi_app=app_handler)) server.start() return RocketServer @@ -370,20 +375,19 @@ def run(self, app): from threading import Lock -_sa_lock = Lock() _srv_log=None def log_info(mess, dbg=True, ): def salog(pat='SA:'): - global _srv_log, _sa_lock - if _srv_log: # and isinstance( _srv_log, logging.Logger ): + global _srv_log + if _srv_log and isinstance( _srv_log, logging.Logger ): return _srv_log hs= [e for e in logging.root.manager.loggerDict if e.startswith(pat) ] if len(hs) == 0: return logger - _sa_lock.acquire() - _srv_log = logging.getLogger(hs[0]) - _sa_lock.release() + sa_lock = Lock() + with sa_lock: + _srv_log = logging.getLogger(hs[0]) return _srv_log From a5b5b1f8880adc9dd37417adb34e3cbf86298254 Mon Sep 17 00:00:00 2001 From: AliBsk Date: Sat, 23 Sep 2023 14:36:02 +0300 Subject: [PATCH 3/6] adding except OSError, ValueError to logging_conf --- py4web/server_adapters.py | 22 +++++++++++++++------- 1 file changed, 15 insertions(+), 7 deletions(-) diff --git a/py4web/server_adapters.py b/py4web/server_adapters.py index 21f2b872c..a1707edcd 100644 --- a/py4web/server_adapters.py +++ b/py4web/server_adapters.py @@ -67,7 +67,7 @@ def logging_conf(level=logging.WARN, logger_name=__name__): log_to["filemode" ] = "w" log_to["encoding"] = "utf-8" - else: # sys.version_info < (3, 9) + else: h = logging.FileHandler( log_file, @@ -82,12 +82,19 @@ def logging_conf(level=logging.WARN, logger_name=__name__): time_msg = '%H:%M:%S' #date_time_msg = '%Y-%m-%d %H:%M:%S' - logging.basicConfig( - format=short_msg, - datefmt=time_msg, - level=check_level(level), - **log_to, - ) + try: + + logging.basicConfig( + format=short_msg, + datefmt=time_msg, + level=check_level(level), + **log_to, + ) + + except ( OSError, KeyError, ValueError ) as ex: + print(f"{ex}, {__file__}") + print(f'cannot open {log_file}') + logging.basicConfig( level=check_level(level),) if logger_name is None: return None @@ -95,6 +102,7 @@ def logging_conf(level=logging.WARN, logger_name=__name__): logger_name = "SA:" + logger_name log = logging.getLogger(logger_name) log.propagate = True + log.info( f'info start logger {logger_name}' ) log.warn( f'warn start logger {logger_name}' ) log.debug( f'debug start logger {logger_name}' ) From f594734a17f9dcc60f67a14f29d69774659d5c8b Mon Sep 17 00:00:00 2001 From: AliBsk Date: Sun, 24 Sep 2023 12:15:57 +0300 Subject: [PATCH 4/6] + except LookupError --- py4web/server_adapters.py | 15 +++------------ 1 file changed, 3 insertions(+), 12 deletions(-) diff --git a/py4web/server_adapters.py b/py4web/server_adapters.py index a1707edcd..456654f9e 100644 --- a/py4web/server_adapters.py +++ b/py4web/server_adapters.py @@ -61,14 +61,11 @@ def logging_conf(level=logging.WARN, logger_name=__name__): log_to = dict() if log_file: - if sys.version_info >= (3, 9): log_to["filename" ] = log_file log_to["filemode" ] = "w" log_to["encoding"] = "utf-8" - else: - h = logging.FileHandler( log_file, mode = "w", @@ -83,29 +80,23 @@ def logging_conf(level=logging.WARN, logger_name=__name__): #date_time_msg = '%Y-%m-%d %H:%M:%S' try: - logging.basicConfig( format=short_msg, datefmt=time_msg, level=check_level(level), **log_to, ) - - except ( OSError, KeyError, ValueError ) as ex: + except ( OSError, LookupError, KeyError, ValueError ) as ex: print(f"{ex}, {__file__}") print(f'cannot open {log_file}') - logging.basicConfig( level=check_level(level),) + logging.basicConfig( level=check_level(level)) if logger_name is None: return None - logger_name = "SA:" + logger_name - log = logging.getLogger(logger_name) + log = logging.getLogger("SA:" + logger_name) log.propagate = True - log.info( f'info start logger {logger_name}' ) - log.warn( f'warn start logger {logger_name}' ) - log.debug( f'debug start logger {logger_name}' ) return log From 6c924ff7b7a3a89eb62eabffd189e0764ec40915 Mon Sep 17 00:00:00 2001 From: AliBsk Date: Sat, 30 Sep 2023 16:08:17 +0300 Subject: [PATCH 5/6] adding short_names: geventWs, wsgiTh --- py4web/server_adapters.py | 29 +++++++++++------------------ 1 file changed, 11 insertions(+), 18 deletions(-) diff --git a/py4web/server_adapters.py b/py4web/server_adapters.py index 456654f9e..b2ce60e9e 100644 --- a/py4web/server_adapters.py +++ b/py4web/server_adapters.py @@ -12,8 +12,8 @@ __all__ = [ "gevent", - "geventWebSocketServer", - "wsgirefThreadingServer", + "geventWebSocketServer", "geventWs", # short_name + "wsgirefThreadingServer", "wsgiTh", # short_name "rocketServer", ] + wsservers_list @@ -79,9 +79,11 @@ def logging_conf(level=logging.WARN, logger_name=__name__): time_msg = '%H:%M:%S' #date_time_msg = '%Y-%m-%d %H:%M:%S' + msg_format = None if 'gevent' in logger_name else short_msg + try: logging.basicConfig( - format=short_msg, + format=msg_format, datefmt=time_msg, level=check_level(level), **log_to, @@ -89,7 +91,7 @@ def logging_conf(level=logging.WARN, logger_name=__name__): except ( OSError, LookupError, KeyError, ValueError ) as ex: print(f"{ex}, {__file__}") print(f'cannot open {log_file}') - logging.basicConfig( level=check_level(level)) + logging.basicConfig( format="%(message)s", level=check_level(level),) if logger_name is None: return None @@ -109,7 +111,7 @@ def get_workers(opts, default=10): # ---------------------- servers ----------------------------------------------- def gevent(): - # gevent version 23.7.0 + # gevent version 23.9.1 import threading from gevent import local, pywsgi # pip install gevent @@ -125,21 +127,13 @@ def gevent(): class GeventServer(ServerAdapter): def run(self, app_handler): - log_file = get_log_file() - logger = "default" if not self.quiet: - logger = logging.getLogger("SA:gevent") - fh = ( - logging.FileHandler() - if not log_file - else logging.FileHandler(log_file, mode='w') + logger = logging_conf( + self.options["logging_level"], "gevent", ) - logger.setLevel(check_level(self.options["logging_level"])) - logger.addHandler(fh) #logger.addHandler(logging.StreamHandler()) - logger.propagate = True certfile = self.options.get("certfile", None) @@ -194,7 +188,6 @@ def run(self, app_handler): self.options["logging_level"], "gevent-ws", ) - certfile = self.options.get("certfile", None) ssl_args = ( @@ -218,7 +211,7 @@ def run(self, app_handler): server.serve_forever() return GeventWebSocketServer - +geventWs=geventWebSocketServer def wsgirefThreadingServer(): # https://www.electricmonk.nl/log/2016/02/15/multithreaded-dev-web-server-for-the-python-bottle-web-framework/ @@ -326,7 +319,7 @@ class ServerClass(Server): srv.serve_forever() return WSGIRefThreadingServer - +wsgiTh=wsgirefThreadingServer def rocketServer(): try: From 13311d8647e78164fdc1b1cbc497adb98163daa4 Mon Sep 17 00:00:00 2001 From: AliBsk Date: Mon, 2 Oct 2023 07:56:36 +0300 Subject: [PATCH 6/6] adding test for log func --- py4web/server_adapters.py | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/py4web/server_adapters.py b/py4web/server_adapters.py index b2ce60e9e..2c9370483 100644 --- a/py4web/server_adapters.py +++ b/py4web/server_adapters.py @@ -55,7 +55,7 @@ def check_level(level): ) -def logging_conf(level=logging.WARN, logger_name=__name__): +def logging_conf(level=logging.WARN, logger_name=__name__, test_log = False): log_file = get_log_file() log_to = dict() @@ -79,11 +79,9 @@ def logging_conf(level=logging.WARN, logger_name=__name__): time_msg = '%H:%M:%S' #date_time_msg = '%Y-%m-%d %H:%M:%S' - msg_format = None if 'gevent' in logger_name else short_msg - try: logging.basicConfig( - format=msg_format, + format=short_msg, datefmt=time_msg, level=check_level(level), **log_to, @@ -99,6 +97,10 @@ def logging_conf(level=logging.WARN, logger_name=__name__): log = logging.getLogger("SA:" + logger_name) log.propagate = True + if test_log: + for func in (log.debug, log.info, log.warn, log.error, log.critical, ) : + func('func: ' + func.__name__ ) + return log