Thursday, 2 January 2020

Logging config fails to the load the value-formatter() when the application has multiple calls

I am using bottle wsgi framework to create webserive. I configured the logger in app.py (shown in the app.py) which receives the application call and passes input parameters to backend.py using the method get_output().I am using the backend.py to process the rquest of the application. In the backend file the logger congif is set using self.logger for every instance of Processor(shown in the backend.py file)

app.py

from bottle import Bottle
import logging.handlers
from backend import Processor

logger = logging.getLogger()
logger.setLevel(logging.DEBUG)

# Logging handler for files
file_handler = logging.handlers.TimedRotatingFileHandler("log.log", when="midnight", interval=1,
                                                         backupCount=10000)
file_handler.setLevel(logging.INFO)

# Logging handler for console
console_handler = logging.StreamHandler()
console_handler.setLevel(logging.DEBUG)

# Formatter's for logging
formatter = logging.Formatter('%(asctime)s %(name)s %(levelname)s %(message)s')
file_handler.setFormatter(formatter)
console_handler.setFormatter(formatter)

# Add handlers to the logger
logger.addHandler(file_handler)
logger.addHandler(console_handler)


class App:

    def __init__(self, host, port, server):
        logger.info("Initializing the app")
        self.processor = Processor()
        self._app = Bottle()
        self._host = host
        self._port = port
        self._server = server

    def _route(self):
        self._app.route('/hello/<attribute>/<number>', method="POST", callback=self.get_output)

    def start(self):
        self._app.run(server=self._server, host=self._host, port=self._port)  ## Starts the service
        logger.info("Web service started.")

    def get_output(self, attribute, number):
        logger.info("Got the input attribute {}".format(attribute))
        result = self.processor.compute(attribute, number)
        return result


if __name__ == '__main__':
    server = App(server='waitress', host='0.0.0.0', port=8080)
    server.start()

backend.py

 import logging


class Processor:

    def __init__(self):
        self.logger = logging.getLogger(__name__)  # Setting the logging config
        self.attribute = None  ############ Setting this variable to None for the instance

    def set_attributes(self, input_attribute):
        self.attribute = input_attribute  ############### Setter to set the attribute

    def compute(self, attribute, number):
        self.set_attributes(attribute)
        self.logger.info("Completed proccesing the attribute {}".format(self.attribute))
        res = number + 5
        return res

Issue is logger picks previous request argument stored in the shared memory (It picks Blue for Green...etc) whenever there are multiple calls to this app.py file.

I recreated the logging statements, as shown below

2019-12-23 15:15:46,992 yoshi INFO Web service started.
Bottle v0.13-dev server starting up (using WaitressServer())...
Listening on http://0.0.0.0:8090/
Hit Ctrl-C to quit.

Serving on http://0.0.0.0:8090

line1: 2019-12-23 15:15:47,327 app.py INFO Got the input attribute Green
line2: 2019-12-23 15:15:47,327 app.py INFO Got the input attribute Blue
line3: 2019-12-23 15:15:47,327 backend.py INFO Completed proccesing the attribute Green
line4: 2019-12-23 15:15:47,327 app.py INFO Got the input attribute Black
line5: 2019-12-23 15:15:47,327 backend.py INFO Completed proccesing the attribute Green <<<-----This needs to be Blue, but it is Green again (Is it because self.attribute = None)
line6: 2019-12-23 15:15:47,327 backend.py INFO Completed proccesing the attribute Black
line7: 2019-12-23 15:15:47,327 backend.py INFO Completed proccesing the attribute None <<<-----This needs to be Violet, but it is None again (Is it because self.attribute = None)
line8: 2019-12-23 15:15:47,327 app.py INFO Got the input attribute Violet

All together I made 4 calls to the above application in parallel with attributes Green, Blue, Black, Violet

Question:

What is the reason my logger fails in line5 and line7? Is the right way to use a setter method to set the input parameter to whole object? (IF not, How to set the input attribute to a whole new module)

Is it because of shared memory used by self.attribute?? How to solve this??

Looking for an answer to create a logging config which can be used in all the modules of my application. where I need to use the request arguments in the log message and the logger config don't get failed by multiple input calls to the application



from Logging config fails to the load the value-formatter() when the application has multiple calls

No comments:

Post a Comment