Working with a group doing radiusScripted authentication.
We upgraded to 4.1.3 today from 4.1.2 and I noticed this in the logs: 06-09-2010 09:00:08.416 DEBUG AuthenticationManagerScripted - First 100 characters of trimmed script output: 'Traceback (most recent call last): File "/opt/splunk/bin/runScript.py", line 69, in e'
Using strings on splunk-4.1.3/bin/splunkd I see: 'First 100 characters of trimmed script output: '%s'
I do not see this line in previous versions of 4.1.X.
Thanks
The output is trimmed for those debug messages only, in order to splunkd.log sane. Previously, we would log the entire script output for each invocation, which was much too verbose.
For instance, imagine the getUsers() function with thousands of users - we wouldn't want to log that. In the majority of cases, our logger would only report something like "Tried to log a xxx byte message, ignoring..." instead of the intended debug message.
Keep in mind this logging output is only meant to provide a brief sanity check on the script. The proper way to debug the script itself is by testing it on its own, without interacting with splunkd. For more information on that, see "Testing the script" in our newly revamped scripted auth docs:
http://www.splunk.com/base/Documentation/latest/Admin/ConfigureSplunktousePAMorRADIUSauthentication
The output is trimmed for those debug messages only, in order to splunkd.log sane. Previously, we would log the entire script output for each invocation, which was much too verbose.
For instance, imagine the getUsers() function with thousands of users - we wouldn't want to log that. In the majority of cases, our logger would only report something like "Tried to log a xxx byte message, ignoring..." instead of the intended debug message.
Keep in mind this logging output is only meant to provide a brief sanity check on the script. The proper way to debug the script itself is by testing it on its own, without interacting with splunkd. For more information on that, see "Testing the script" in our newly revamped scripted auth docs:
http://www.splunk.com/base/Documentation/latest/Admin/ConfigureSplunktousePAMorRADIUSauthentication
Whoa, I like the new ScriptedAuth doc.
Thanks Marklar and Josh.
It looks like there's no facility to get the entire output at this point. I will log an item to request the full output.
Short term options: 1 - drop in a wrapper to dup the output to a file 2 - strace the splunkd child process with flags to get all the text, and see it passed through the read calls along the pipe
Well, debugging a failure, or rather, developing the authentication scripts in a custom setup. Since these messages only reach the splunkd.log when ScriptedAuthentication is in debug mode, it seems strange to me to truncate it. I mean, if you are in debug mode, then you are debugging; therefore, seeing all of the output is valuable.
I figured I was just missing something here and there was some other reason for the change in 4.1.3.
Thanks again for following up.
I expect it was trimmed because a valid reponse is always 1 line long. The use case presented here is debugging a failure though.
Thanks for the response Josh. Can you tell me why PM added this restriction? I guess I was wondering, what scenario caused the condition that resulted in this protection being added? Were splunkd.log DOSed?
Note: Although I still would like an answer to "1" above, I do feel like I successfully tested out "2" and Splunk DOES use all of the output from a script even though only the first 100 characters are sent do splunkd.log.
I would love some input from dev/PM on this when possible.