View source for Enhanced-context-logger-oslo

== Blueprint Design for ([https://blueprints.launchpad.net/oslo/+spec/enhanced-context-logger enhanced-context-logger]) ==
=== Problem Statement ===
Currently, the logger does not provide any means to the drivers or consumers to add any additional contextual information other than the one that has been baked into the logger e.g. instanceId. The blueprint is going to add the flexibility to the logger, so that if needed the consumer of the logger could add some contextual data that can then show up in the logs without changing the individual log statements throughout the code.

=== Proposed Design ===
The idea is to introduce a placeholder for sub-contextual information. The logic would run based on the presence of such placeholder. The classes that would be enhanced in the process would be the '''openstack.common.log.ContextAdapter''' and '''openstack.common.log.ContextFormatter'''

==== Proposed modification to the '''ContextAdapter''' ====
Add a placeholder named "sub_context" within the "extra", and if found unroll it into the "extra" like below:

        extra.update({"version": self.version})
        '''if extra.get('sub_context', None):'''
            '''sub_context = extra.get('sub_context', None)'''
            '''for k in sub_context:'''
                '''extra.update({k:sub_context[k]})'''
        extra['extra'] = extra.copy()


==== Proposed modification to the '''ContextFormatter''' ====

        self._fmt += " " + CONF.logging_debug_format_suffix
        '''if record.__dict__.get('sub_context', None):'''
            '''sub_context = record.__dict__.get('sub_context', None)'''
            '''for k in sub_context:'''
                '''self._fmt += " [" + k + ":%(" + k + ")s]"'''


=== Proposed usage of this enhanced logger ===
Within a driver code, one would add the following at an appropriate place based on the information they want to add to the logger

    def _enhance_context(self, func):
        "This decorator enhances the context with a module specific contextual information"
        argnames = func.func_code.co_varnames[:func.func_code.co_argcount]
    
        def enhance_process(*args,**kwargs):
            if 'kwargs' in argnames:
                pkwargs = args[argnames.index('kwargs')]
                if 'extra' not in pkwargs:
                    pkwargs['extra'] = {}
                extra = pkwargs['extra']
                if 'sub_context' not in extra:
                    extra['sub_context'] = {}
                sub_context = extra['sub_context']            
                sub_context.update({"my_context": self._my_context_value})
            return func(*args, **kwargs)
  
        return enhance_process
  
    def _enhancelogger(self):
        setattr(logging.ContextAdapter, 'process', self._enhance_context(logging.ContextAdapter.process))


The revised logs may look like:<br />
''2014-01-17 13:09:06.815 DEBUG nova.compute.manager [-] '''[my_context: my_context_value]''' [instance: c0efa837-3a21-4b08-91f9-995e2ee2adb9] Updated the info_cache for instance from (pid=11649) _heal_instance_info_cache /opt/stack/nova/nova/compute/manager.py:4437''