vavarachen/splunk_hec_handler

Error "Log record emit exception raised."

Closed this issue · 9 comments

Hi,

i use the Splunk HEC handler to log messages on a debug level, however, sometimes there is
a log message from handler itself appearing in the logs:

[DEBUG] Log record emit exception raised. Exception: 'int' object has no attribute 'count'

(i suppose the only content logged here was an 'int' type, which works perfectly with a debug on a
standard Logger, but not with Splunk handler)

Other times there is another error message:

[DEBUG] Log record emit exception raised. Exception: invalid syntax (<unknown>, line 1)

I have no idea what is going on here.

@aellwein can you share few more details around the code. Typically Splunk HEC handler would raise an exception if it is unable to POST to the Splunk forwarder.

Without knowing what type of an object you passed to the log handler, it is difficult to troubleshoot.

Example below logs an int to Splunk in debug mode without any issues.

import logging
from splunk_hec_handler import SplunkHecHandler
logger = logging.getLogger('test')
logger.setLevel(logging.DEBUG)
splunk_handler = SplunkHecHandler('localhost', '2bbe07bd-6900-4429-b46e-7305c189890f', port=8088, proto='http')
logger.addHandler(splunk_handler)
logger.debug(1)

May I comment on the issue, although the thread is some months old.
We experienced here the same log messages mentioned above.

@vavarachen I can reproduce the log messages with your example by setting the root logger's log level to DEBUG right after the imports with
logging.getLogger().setLevel(logging.DEBUG)

python 3.8.2 splunk-hec-handler 1.0.9

@vavarachen sorry i totally missed to answer you.
Since i have no access to my Splunk system anymore, i am currently unable to reproduce this issue.
But as with good hint from @kala-nag, the root logger's level was set to logging.DEBUG. Hope this helps.

@aellwein / @kala-nag ,

Thank you for identifying the bug. I have addressed it in the latest release.

Thank you @vavarachen for working on this.
Your example works with the new release, but if I try a string instead a number as argument I still get the error message:

logger.debug("Hello World")

# CONSOLE:
# DEBUG:root:Log record emit exception raised. Exception: unexpected EOF while parsing (<unknown>, line 1)
# DEBUG:urllib3.connectionpool:Starting new HTTP connection (1): localhost:8080
# DEBUG:urllib3.connectionpool:http://localhost:8080 "POST /services/collector/event HTTP/1.1" 200 17
# DEBUG:test:Hello World

@kala-nag
Can you check if you are running the latest version?

$ pip list | grep splunk-hec-handler
splunk-hec-handler 1.1.0

[ins] In [4]: import logging
...: from splunk_hec_handler import SplunkHecHandler
...: logger = logging.getLogger('test')
...: logger.setLevel(logging.DEBUG)
...: splunk_handler = SplunkHecHandler('localhost', 'e706da8b-695e-4d2e-8503-c947917e073e', port=8088, proto='http')
...: logger.addHandler(splunk_handler)
...: logger.debug("Hello World")
DEBUG:test:Hello World

Hi @vavarachen, yes it's: splunk-hec-handler 1.1.0
the example:

import logging
from splunk_hec_handler import SplunkHecHandler

import pkg_resources                         #<------ added to check version
print(f'*** Version check splunk_hec_handler: {pkg_resources.get_distribution("splunk_hec_handler").version}')

logging.getLogger().setLevel(logging.DEBUG)  #<------ this line added to the example

logger = logging.getLogger('test')
logger.setLevel(logging.DEBUG)
splunk_handler = SplunkHecHandler('localhost', 'e706da8b-695e-4d2e-8503-c947917e073e', port=8088, proto='http')
logger.addHandler(splunk_handler)
print('*** no output in console  - in Splunk: ... "message": 1 ...   i.e. OK')
logger.debug(1)
print('*** no output in console  - in Splunk: ... "message": 1 ...  minor problem:  Integer!')
logger.debug("1")
print('*** exception in console  - in Splunk: ... "message": "Hello World" ...  i.e. OK')
logger.debug("Hello World")

Console output:

*** Version check splunk_hec_handler: 1.1.0
*** no output in console  - in Splunk: ... "message": 1 ...   i.e. OK
*** no output in console  - in Splunk: ... "message": 1 ...  minor problem:  Integer!
*** exception in console  - in Splunk: ... "message": "Hello World" ...  i.e. OK
DEBUG:root:Log record emit exception raised. Exception: unexpected EOF while parsing (<unknown>, line 1) 
DEBUG:urllib3.connectionpool:Resetting dropped connection: localhost
DEBUG:urllib3.connectionpool:http://localhost:8088 "POST /services/collector/event HTTP/1.1" 200 2
DEBUG:test:Hello World

@kala-nag

While the "hello world" string is properly logged to Splunk, the debug message appears to be a side-effect of ast module. I think It is safe to ignore that debug message. I will likely remove it in the future release.

    try:
        if record.msg.__class__ == dict:
            # If record.msg is dict, leverage it as is
            body.update(record.msg)
        else:
            # Check to see if msg can be converted to a python object
            body.update({'message': ast.literal_eval(str(record.msg))})
    except Exception as err:
       # The following debug statement is pointless, since we proceed with the record message if ast conversion fails.
        logging.debug("Log record emit exception raised. Exception: %s " % err)
        body.update({'message': record.msg})

The code uses the ast module, which is handy when handling cases where the log message might be a proper python data type.

In the example below, the 'dict_as_string' will get converted to a proper dict and logged as such.

import logging
from splunk_hec_handler import SplunkHecHandler
logging.getLogger().setLevel(logging.DEBUG)
logger = logging.getLogger('test')
logger.setLevel(logging.DEBUG)
splunk_handler = SplunkHecHandler('localhost', 'e706da8b-695e-4d2e-8503-c947917e073e', port=8088, proto='http')
logger.addHandler(splunk_handler)
dict_as_string = "{'a': 1, 'b': 2, 'c': [1,2,3]}"
logger.debug(dict_as_string)

Thank you for pointing out the issue.

@vavarachen Thank you for your effort and explanation.