census-instrumentation / opencensus-python

A stats collection and distributed tracing framework
Apache License 2.0
669 stars 250 forks source link

The record is not being sent to Azure if it has exc_info #1190

Closed greatvovan closed 1 year ago

greatvovan commented 1 year ago

Environment

Python 3.10.8

pip freeze ``` azure-core==1.26.3 azure-identity==1.12.0 cachetools==5.3.0 certifi==2022.12.7 cffi==1.15.1 charset-normalizer==3.0.1 cryptography==39.0.1 google-api-core==2.11.0 google-auth==2.16.0 googleapis-common-protos==1.58.0 idna==3.4 msal==1.21.0 msal-extensions==1.0.0 opencensus==0.11.1 opencensus-context==0.1.3 opencensus-ext-azure==1.1.8 portalocker==2.7.0 protobuf==4.21.12 psutil==5.9.4 pyasn1==0.4.8 pyasn1-modules==0.2.8 pycparser==2.21 PyJWT==2.6.0 requests==2.28.2 rsa==4.9 six==1.16.0 typing_extensions==4.4.0 urllib3==1.26.14 ```

Steps to reproduce

Run the code (with a valid InstrumentationKey):

import sys
import logging
from opencensus.ext.azure.log_exporter import AzureLogHandler

logger = logging.getLogger('ribbit')
logger.addHandler(AzureLogHandler(connection_string='InstrumentationKey=...'))
logger.addHandler(logging.StreamHandler(sys.stdout))
logger.warning(42)

try:
    1 / 0
except Exception:
    logger.exception('1/0')

What is the expected behaviour?

Equivalent output of both handlers.

What is the actual behaviour?

The code will print both 42 and 1/0 locally, but only 42 will go to Azure.

Additional context

I figured out that if I remove exc_info from the record here https://github.com/census-instrumentation/opencensus-python/blob/b85e4767edcd6524515d263853247335f9ee69f4/contrib/opencensus-ext-azure/opencensus/ext/azure/log_exporter/__init__.py#L109 before sending to the queue, it starts working. I did not chase it further. Also it does not print any errors.

This does not seem to be a recent problem. I tried it with versions 1.1.0, 1.0.0, 0.7.1, and the result is the same.

greatvovan commented 1 year ago

The workaround I invented so far:

def patch_azure_log_handler():
    """
    As of version opencensus-ext-azure==1.1.8, the handler fails to send
    a log record to the cloud if the record has exc_info.
    Here we convert most useful information from exc_info into
    customDimensions dynamic field of traces table and reset exc_info.

    See https://github.com/census-instrumentation/opencensus-python/issues/1190
    """
    from opencensus.ext.azure.log_exporter import BaseLogHandler
    from traceback import format_exception

    def emit(self, record):
        if record.exc_info:
            exc_type, exc_object, exc_trace = record.exc_info
            cd = getattr(record, 'custom_dimensions', None)

            if cd is None:
                cd = {}
                record.custom_dimensions = cd

            cd['excType'] = exc_type.__name__
            cd['excMessage'] = str(exc_object)
            cd['excTrace'] = ''.join(format_exception(exc_object))

            record.exc_info = None

        BaseLogHandler.old_emit(self, record)

    BaseLogHandler.old_emit = BaseLogHandler.emit
    BaseLogHandler.emit = emit

Please post if you have improvement suggestions.

greatvovan commented 1 year ago

My apologies for false alert, I am a new user and I did not realize that the exceptions go into exceptions table rather than regular traces table. With that caveat everything works great.

Having said that, I think it is a questionable design to differentiate destinations based on presence of exc_info, because Logger.warning(obj, exc_info=True) will go to exceptions table besides being a warning level record.