Apache Avg Response Time

[ChicagoKid]

Hi everyone, I have exhausted the guess and click on this.

I'm learning Splunk by following the book Operational intelligence Cookbook Volume 2 and I have hit a wall.
The Recipe I'm working on is supposed to chart an applications functional statics, here is the code in the book.

 index = main sourcetype = log4j 
| eval mem_used_MB =( mem_used/ 1024)/ 1024 
| eval mem_total_MB =( mem_total/ 1024)/ 1024 
| timechart span = 1m values( mem_total_MB) AS Total_Mem_Avail_MB, count AS Total_Calls, avg( mem_used_MB) AS Avg_Mem_Used_MB, avg( response_time) AS Avg_Response_Time

This works fine except that AVG_Response_Time produces no values.

I changed the code someone to also use sourcetype="access_combined" and instead of AS Avg_Response_Time I changed it to just avg_response and added the round function.

index=main sourcetype=log4j OR sourcetype="access_combined" 
| eval mem_used_MB=(mem_used/1024)/1024 
| eval mem_total_MB=(mem_total/1024)/1024 **
|eval avg_response=round(response/1000,2)** 
|timechart span=1m values(mem_total_MB) AS Total_Mem_Avail_MB, count AS Total_Calls, avg(mem_used_MB) AS Avg_Mem_Used_MB, avg(avg_response) As avg_response_time

Now the avg_response responses times show up in the statistics output but I'm wondering why the books code did not work? Why did I have to add another sourcetype?
Should I have added a field "response_time" in field extractor?

What am I missing?

Thanks for any help

[ChicagoKid]

Thanks dbcase and dwaddle for your help.

[dbcase]

you are welcome!

[dwaddle]

You need to make sure your data has the data for the fields you're trying to use - and that they are being extracted correctly - before you can do analytics operations against them. Echoing the suggestion of @dbcase, for sourcetype=access_combined (the default Apache log format) there is no existing "time spent" or "duration" or "response time" or anything like that. You would need to make sure it gets added.

Splunk internally has some log file formats that are substantially similar to access_combined like splunkd_web_access that include more detail in the log events and additional field extractions to get the fields from that data. For example:

Here's 1 event:

127.0.0.1 - admin [21/Feb/2017:09:33:37.991 -0600] "GET /services/search/timeparser/tz HTTP/1.0" 200 3390 - - - 1ms

And the props.conf for that sourcetype:

[splunkd_access]
maxDist = 28
MAX_TIMESTAMP_LOOKAHEAD = 128
REPORT-access = access-extractions, extract_spent
SHOULD_LINEMERGE = False
TIME_PREFIX = \[

And the transforms.conf for extract_spent:

[extract_spent]
REGEX   = \s(?P<spent>\d+(\.\d+)?)ms$

With spent being in the data (1ms) and being properly extracted, it's easy for me now to:

 index=_internal sourcetype=splunkd_access | stats avg(spent)

With Apache logs in general, what I would personally suggest is if you're going to modify the format of access_combined, then add new fields to the END, and do them as key=value. Then you don't have to change anything and Splunk just picks it up.

[dbcase · Accepted solution]

to verify that Apache is actually logging the micro seconds check your httpd.conf file for an entry that is similar to the below

LogFormat "\"%{Host}i\" %h \"%{X-Forwarded-For}i\" %l %u %t \"%r\" %>s %b %T %D \"%{Referer}i\" \"%{User-Agent}i\" \"%{X-icErrorCode}o\"" combined

The %D is the critical piece. That is the configuration option that tells apache to include the micro seconds that it took to execute the command.

You can see all the apache configuration options here . http://httpd.apache.org/docs/current/mod/mod_log_config.html

[somesoni2]

It could be that field response_time is not extracted (correctly) in sourcetype=log4j or the raw data for log4j doesn't contain the response_time at correct place or not present at all.