Archive

AuthenticationManagerScripted Trimmed Script Output

Contributor

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.

  1. How can I override this "feature" and see more DEBUG output?
  2. Is there any possibility that this "100 character" throttle effects what is parsed by the authentication system or just what is sent to splunkd.log?

Thanks

Tags (2)
1 Solution

Splunk Employee
Splunk Employee

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

View solution in original post

Splunk Employee
Splunk Employee

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

View solution in original post

Contributor

Whoa, I like the new ScriptedAuth doc.

Thanks Marklar and Josh.

0 Karma

Splunk Employee
Splunk Employee

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

Contributor

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.

0 Karma

Splunk Employee
Splunk Employee

I expect it was trimmed because a valid reponse is always 1 line long. The use case presented here is debugging a failure though.

0 Karma

Contributor

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?

0 Karma

Contributor

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.

0 Karma