Python alert script fails and I can't see errors in the logs. How can I tell why?

[ramabu]

I have a set of python alert scripts that do basically the same thing, but I don't see them run successfully (the WEB service post that they do doesn't happen). I do see them in the triggered alerts though.

So I looked for the "runshellscript" lines in the python.log.

First I made sure that the script does what I want. When I run the command as it appears there, it fails:

[root@rama-splunk splunk]# "/opt/splunk/bin/python" "/opt/splunk/etc/apps/SplunkforCounterACT/bin/scripts/trigger_fsremediate.py" "3" "index=fsctcenter ctupdate=notif pleaseAlertMe2" "index=fsctcenter ctupdate=notif pleaseAlertMe2" "trigger_remediate_action" "Saved Search [trigger_remediate_action] number of events(3)" "http://rama-splunk.networking.lab.forescout.com:8000/app/SplunkforCounterACT/search?q=%7Cloadjob%20scheduler__nobody__SplunkforCounterACT__RMD58498d9b24b108e27_at_1455814800_9726%20%7C%20head%201%20%7C%20tail%201\&earliest=0\&latest=now" "" "/opt/splunk/var/run/splunk/dispatch/scheduler__nobody__SplunkforCounterACT__RMD58498d9b24b108e27_at_1455814800_9726/per_result_alert/tmp_0.csv.gz"
ERROR:root:code for hash md5 was not found.
Traceback (most recent call last):
  File "/opt/splunk/lib/python2.7/hashlib.py", line 147, in <module>
    globals()[__func_name] = __get_hash(__func_name)
  File "/opt/splunk/lib/python2.7/hashlib.py", line 97, in __get_builtin_constructor
    raise ValueError('unsupported hash type ' + name)
ValueError: unsupported hash type md5
ERROR:root:code for hash sha1 was not found.
Traceback (most recent call last):
  File "/opt/splunk/lib/python2.7/hashlib.py", line 147, in <module>
    globals()[__func_name] = __get_hash(__func_name)
  File "/opt/splunk/lib/python2.7/hashlib.py", line 97, in __get_builtin_constructor
    raise ValueError('unsupported hash type ' + name)
ValueError: unsupported hash type sha1
Traceback (most recent call last):
  File "/opt/splunk/etc/apps/SplunkforCounterACT/bin/scripts/trigger_fsremediate.py", line 2, in <module>
    import fsutil
  File "/opt/splunk/etc/apps/SplunkforCounterACT/bin/scripts/fsutil.py", line 10, in <module>
    from splunk.clilib import cli_common as cli
  File "/opt/splunk/lib/python2.7/site-packages/splunk/clilib/cli_common.py", line 6, in <module>
    import lxml.etree as etree
ImportError: /usr/lib64/libxml2.so.2: version `LIBXML2_2.9.0' not found (required by /opt/splunk/lib/python2.7/site-packages/lxml/etree.so)

But when I run it this way it succeeds:

$SPLUNK_HOME/bin/splunk cmd python "/opt/splunk/etc/apps/SplunkforCounterACT/bin/scripts/trigger_fsremediate.py" "3" "index=fsctcenter ctupdate=notif pleaseAlertMe2" "index=fsctcenter ctupdate=notif pleaseAlertMe2" "trigger_remediate_action" "Saved Search [trigger_remediate_action] number of events(3)" "http://rama-splunk.networking.lab.forescout.com:8000/app/SplunkforCounterACT/search?q=%7Cloadjob%20scheduler__nobody__SplunkforCounterACT__RMD58498d9b24b108e27_at_1455814800_9726%20%7C%20head%201%20%7C%20tail%201\&earliest=0\&latest=now" "" "/opt/splunk/var/run/splunk/dispatch/scheduler__nobody__SplunkforCounterACT__RMD58498d9b24b108e27_at_1455814800_9726/per_result_alert/tmp_0.csv.gz"
Response:  200 OK
Headers:  Date: Thu, 18 Feb 2016 17:31:18 GMT
Server: Apache
X-FRAME-OPTIONS: SAMEORIGIN
X-XSS-PROTECTION: 1;MODE=BLOCK
X-CONTENT-TYPE-OPTIONS: NOSNIFF
Set-Cookie: JSESSIONID=A8338C09AA175FF33A08FE4986C137AF; Path=/; HttpOnly
Content-Length: 194
Connection: close

Content:  <?xml version="1.0" encoding="UTF-8"?>
<SPLUNK_ALERTS TYPE="response">
<STATUS>
    <CODE>200</CODE>
    <MESSAGE>Set Disposition [2] to host [10.41.2.103]</MESSAGE>
</STATUS>
</SPLUNK_ALERTS>

How does splunk start the script? Is it one of the above?
Where if at all do I see the script's standard output?
How can I troubleshoot this?

[richgalloway · Accepted solution]

Use the second form, splunk cmd python ..., to run your scripts manually. It makes sure the environment is correct.
Standard output from the script is indexed by Splunk. Search source="*/trigger_fsremediate.py" to find the output. Find errors by searching index=_internal source="*/splunkd*" component=ExecProcessor.
Troubleshooting more of a problem. AFAIK, the python log no longer exists. I haven't yet discovered a reliable way to determine why scripts fail to run or fail while running.

[jkat54]

I found dcutils getLogger() to be a pretty swift solution (stolen from other splunk python code):

import splunk.mining.dcutils as dcu
logger = dcu.getLogger()
logger.info("this string will be found in python.log")
logger.warn()
logger.error()
logger.exception()
logger.debug

It works so long as you execute it as mentioned by Rich. Inputs will look like this

Windows:
$SPLUNK_HOME\bin\splunk.exe cmd python ..\etc\apps\SplunkforCounterACT\bin\scripts\trigger_fsremediate.py  

Linux:
$SPLUNK_HOME/bin/splunk cmd python ../etc/apps/SplunkforCounterACT/bin/scripts/trigger_fsremediate.py 

Or as a scripted input via inputs.conf examples below:

#Example Inputs.conf# 

#windows input, will be auto-disabled by splunk if application is installed on linux env
[script://$SPLUNK_HOME\etc\apps\SplunkforCounterACT\bin\scripts\trigger_fsremediate.py ]
index = _internal
interval = */30 * * * *
source = trigger_fsremediate.py
sourcetype = sourcetypeName

#linux input, will be auto-disabled by splunk if found on windows env
[script://$SPLUNK_HOME/etc/apps/SplunkforCounterACT/bin/scripts/trigger_fsremediate.py ]
index = _internal
interval = */30 * * * *
source = trigger_fsremediate.py
sourcetype = sourcetypeName