Showing posts with label Logging. Show all posts
Showing posts with label Logging. Show all posts

Friday, 8 March 2013

Log file class with Minimal Python Libraries

Hi Everyone,

Its been a long time since I was here, but I have worked on many scripts in the mean time and I think it would be nice to share a few!

I thought I would start with a small script I wrote about a year ago, the output of which was intended to be consumed by Splunk. Now I look at this, it could also be useful straight away for any work which wanted to keep a simple log file.

The reason I wrote this with 'time' as the only python import is because it was due to run on a hardware system with an old, cut back python installation. This may be an advantage for some, it should at least run on nearly any version of python out there.

The output is a nice timestamped line with all the key=value pairs displayed as strings. (quoted where necessary)


'''
A script to write simple timestamped logs to a file. 
@author: HRH

Example test usage below. Built with limited libraries
due to the tiny python installation where this script is
first intended to be used. 

'''
import time

class SplunkLog:
    
    # Writes a line to the given file with the current timestamp
    # the data value should be a python dictionary where the key => val is 
    # used for logtype=logtext 
    def write_local_log(self,fh,data):
        t = time.localtime()
        logtime = str(t[0])+"-"+str(t[1]).zfill(2)+"-"+str(t[2]).zfill(2)+" "+str(t[3]).zfill(2)+":"+str(t[4]).zfill(2)+":"+str(t[5]).zfill(2)
        log_line = logtime + "\t"
        for row in data:
            for k , v in row.iteritems():
                if " " in v:
                    log_line += k + "=" + '"' + v + '"' + ",\t"
                else:
                    log_line += k + "=" + v + ",\t"
            
        # Write the line, minus the last spacing and with added newline
        log_line = log_line.rstrip(",\t") + "\n"
        fh.write(log_line)


'''
#
#    A usage example - remember to include or add the main class somewhere
#
#
#
#        Main Loop
#
from sys import exit
dummy_data = []
dummy_data.append({"severity" : "Warning","EventID": "Bad Login", "user" : "Test"})
dummy_data.append({"severity" : "Major","EventID": "Possible DoS", "user" : "Remote"})
s = SplunkLog()

try:
    fh = open("splunk-test.txt",'a')
except:
    print "Unable to open log file"
    exit(1)
    
# If we are still here, then we can try write something into the file
for log in dummy_data:
    s.write_local_log(fh, log)

fh.close()
exit(0)
'''

Thursday, 28 October 2010

Python Squid Log Analyser

The Python Squid Log Analyser is a small Python script which will read Squids access.log file and produces a report on:
  • Caching performance
  • Data transfer
  • most requested domains (by hits and by data transfer)
  • most requesting hosts (by hits and by data transfer)

My initial reasons for writing this were to take a look into the Squid caching performance and because I wanted to learn a bit more Python. (Being mostly used to PHP and Bash)
As I started to write this, it made sense to include statistics on the other things happening in the access.log file, since the script read through it all anyway, and so I ended up with a nice summary of daily usage. The way this runs on my system, is within a Bash script, which copies the access.log.1.gz file (yesterdays stats) at 5am each morning. It then extracts and renames it, runs the python against it and emails out the result. I hope this can be useful to someone else!


THE SCRIPT

'''
Created on Oct 11, 2010

@author: His Royal Highness

The squid log reader will analyse the squid access.log file and produce stats on its
content. it expects access.log to be in the same directory, 
but this can be changed to an absolute path as requried.
'''

''' VARIABLES '''
filename = "access.log"
file = open(filename)
''' Request Variables '''
total_requests = 0
total_cache_hits = 0
total_cache_misses = 0
''' Byte Total Variables '''
total_requested_bytes = 0
total_cache_bytes = 0
total_miss_bytes = 0
total_other_bytes = 0
host_requests = {}
host_total_bytes = {}
domain_requests = {}
domain_bytes = {}

''' Strip back URL to what we will measure on '''
def striptodomain(url):
    stripped = url.replace("http://", "")
    #stripped = stripped.repace("www.")
    bits = stripped.split('/')
    hostname = bits[0]
    return hostname


''' Rip through the file and generate the stats '''
for line in file:
    bit = line.split()
    total_requests += 1

    ''' Add in the host request and bytes totals '''
    if bit[2] in host_requests:
        host_requests[bit[2]] += 1
        host_total_bytes[bit[2]] = int(host_total_bytes[bit[2]]) + int(bit[1])
    else:
        host_requests[bit[2]] = 1
        host_total_bytes[bit[2]] = int(bit[1])
        
                
    ''' Add in the Domain request and bytes totals '''
    hostname = striptodomain(bit[6])
    if hostname in domain_requests:
        domain_requests[hostname] += 1
        domain_bytes[hostname] = int(domain_bytes[hostname]) + int(bit[1])
    else:
        domain_requests[hostname] = 1
        domain_bytes[hostname] = int(bit[1]) 
    
        
        
    if 'TCP_HIT' in line or 'TCP_MEM_HIT' in line or 'TCP_NEGATIVE_HIT' in line or 'TCP_IMS_HIT' in line or 'TCP_REFRESH_HIT' in line:
        total_cache_hits += 1                       
        total_cache_bytes += int(bit[1])
        total_requested_bytes += int(bit[1])
        
    elif "TCP_MISS" in line or 'TCP_REFRESH_MISS' in line or 'TCP_CLIENT_REFRESH_MISS' in line:
        total_cache_misses += 1
        total_miss_bytes += int(bit[1])
        total_requested_bytes += int(bit[1])
        
    else:
        total_other_bytes += int(bit[1])
        total_requested_bytes += int(bit[1])
file.close()

    
''' Extra file stats '''        
total_other = (total_requests - total_cache_hits) - total_cache_misses


''' Calculate Percent values '''
total_cache_hits_pc = round((1.0 * total_cache_hits / total_requests) * 100,2)
total_cache_misses_pc = round((1.0 * total_cache_misses / total_requests) * 100,2)
total_other_pc = round((1.0 * total_other / total_requests) * 100,2)

total_cache_bytes_pc = round((1.0 * total_cache_bytes / total_requested_bytes) * 100,2)
total_miss_bytes_pc = round((1.0 * total_miss_bytes / total_requested_bytes) * 100,2)
total_other_bytes_pc = round((1.0 * total_other_bytes / total_requested_bytes) * 100,2)

    

''' File type counts'''
print ""
print "Caching Performance"
print "Total requests: \t\t", total_requests
print "Total Cache hits:\t\t",total_cache_hits, total_cache_hits_pc, "%"
print "Total Cache misses:\t" ,total_cache_misses, total_cache_misses_pc, "%"
print "Total Other:\t\t" ,total_other, total_other_pc, "%"
print ""
print "Total bytes: \t\t", total_requested_bytes
print "Total Cache bytes:\t",total_cache_bytes, total_cache_bytes_pc, "%"
print "Total Miss bytes:\t\t",total_miss_bytes, total_miss_bytes_pc, "%"
print "Total Other bytes:\t",total_other_bytes, total_other_bytes_pc, "%"
print ""
print ""
print ""




''' Print Domain statistics '''
#sorted_domain_requests = sorted(domain_requests)
print "Most Requested Domains (hits)"
temp_list = domain_requests.keys()
temp_list.sort( key = domain_requests.__getitem__, reverse = True)
for a in range(25):
    print domain_requests[temp_list[a]]  , "\t\t" , temp_list[a]
print ""
print ""


print "Highest Data Transfer by Domain (bytes)"
temp_list = domain_bytes.keys()
temp_list.sort( key = domain_bytes.__getitem__, reverse = True)
for a in range(25):
    print domain_bytes[temp_list[a]]  , "\t" , temp_list[a]
print ""
print ""

print "Most requesting hosts (hits)"
temp_list = host_requests.keys()
temp_list.sort( key = host_requests.__getitem__, reverse = True)
if len(temp_list) < 25:
    hosts = len(temp_list)
else:
    hosts = 25
for a in range(hosts):
    print host_requests[temp_list[a]]  , "\t" , temp_list[a]
print ""
print ""

print "Highest Data Transfer by Host (bytes)"
temp_list = host_total_bytes.keys()
temp_list.sort( key = host_total_bytes.__getitem__, reverse = True)
for a in range(hosts):
    print host_total_bytes[temp_list[a]]  , "\t" , temp_list[a]
print ""
print ""

EXAMPLE OUTPUT - (Reduced and formatted)
Total requests:             2419883
Total Cache hits:          573516 23.7 %
Total Cache misses:     1845764 76.27 %
Total Other:                 603 0.02 %

Total bytes:                 5314660302
Total Cache bytes:      37366112 0.7 %
Total Miss bytes:         5273482834 99.23 %
Total Other bytes:       3811356 0.07 %

Most Requested Domains (hits)
78374           www.thomascook.com
73540           urs.microsoft.com:443
58916           sis.baa.com:443

Highest Data Transfer by Domain (bytes)
488356114       sitatex1.mconnect.aero:443
406234484       mail.google.com:443
271621761       b.mail.google.com:443

Most requesting hosts (hits)
83045   128.1.197.202
51284   172.16.248.116
38608   128.1.93.30

Highest Data Transfer by Host (bytes)
487945744       172.16.0.41
237554573       172.16.0.154
157165427       128.1.8.251


NOTES
  • The script can take a couple of minutes to run on large log files and is CPU intensive . In my environment, I am analysing ~400M files and it takes just over a minute.
  • The \t's in the output formatting have been configured to display in outlook, as I have this report sent via email. Running from the CLI may show badly indented columns.
  •  The script expects the access.log file to be in its own directory. If this is not the case, you can change the filename variable at the top from "access.log" to whatever is required. (Likely to be /var/log/squid/access.log if you are running on the box where squid is installed)
  • On my setup, logrotate was configured to move the access.log file on a weekly basis. As I wanted to produce a daily report, I changed the settings in /etc/logrotate.d/squid to daily and increased the rotate number.
  • The function strip to domain could definitely be improved, I was experimenting with splitting the host and taking the -2,-1 values to form the domain. If I had more time, I could have entered all TLDs, made a note of which the current URLs came from and strip it back based on that, but then you also run into the problem for sites like maps.google.com, which you may want to distinguish from www.google.com. If anyone has any ideas for this, I’d be interested to hear them.
  • Finally, I wrote this while learning Python, so all criticism is welcomed so as long as it is constructive!