import repository from arizona
[raven.git] / 2.0 / python / logging / storklog.py
1 #! /usr/bin/env python
2 """
3 <Program Name>
4    storklog.py
5
6 <Author>
7    Programmed by Jeffry Johnston
8
9 <Purpose>
10    Performs data collection, interpretation, and transfer.
11 """
12
13 #           [option, long option,     variable,     action,  data,                                         default, metavar, description]
14 """arizonaconfig
15    options=[
16             ["",       "--lockdir",            "lockdir",              "store",       "string", "/var/lock",                        "dir",   "use the specified mutex lock directory (default /var/lock)"],
17             ["",     "--logdir",      "logdir",     "store", "string", "/tmp",                             "DIR",   "log file directory (default: /tmp)"],
18             ["",     "--uploaddir",   "uploaddir",  "store", "string", "logs",                             "DIR",   "remote host upload directory (default: logs)"],
19             ["",     "--uploadhost",  "uploadhost", "store", "string", "logging@stork-log.cs.arizona.edu",      "HOST",  "remote host name (default: logging@nr05.cs.arizona.edu)"],
20             ["",     "--identitykey", "idkey",      "store", "string", "/usr/local/stork/bin/logging.key", "FILE",  "private key filename (default: /usr/local/stork/bin/logging.key)"],
21             ["",     "--enablelogging","enablelogging","store_true", None, False,                           None,   "enable nest logging (off by default)"]
22            ]
23    includes=[]        
24 """
25
26 import os
27 import syslog
28 import arizonageneral
29 import arizonaconfig
30 import time
31 import arizonareport
32 import sys
33 import storkerror
34 import random
35 import re
36
37 # globals
38 nodehost = ""
39 nodeuser = ""
40 clienthost = ""
41 clientip = ""
42 clientport = ""
43 clientuser = ""
44
45
46
47
48
49 def set_client(hostname, ip, port, username):
50    """ TODO comment """
51    global clienthost, clientip, clientport, clientuser
52    if hostname != None:
53       clienthost = hostname
54    if ip != None:
55       clientip = ip
56    if port != None:
57       clientport = port
58    if username != None:
59       clientuser = user
60
61 def get_hostname():
62    hostname = None
63    try:
64       hostname = arizonageneral.gethostname()
65    except:
66       pass
67    if hostname == None:
68       hostname = "unknown_host"
69    return hostname
70
71 def get_username():
72    try:
73       username = arizonageneral.getusername()
74    except:
75       username = "unknown_user"
76    return username
77
78 def get_connect_log_filename():
79    hostname = get_hostname()
80    return "connect-"+hostname
81
82 def log_connect(what, data = None):
83    # see if we should log this
84    enable = arizonaconfig.get_option("enablelogging")
85    logdir = arizonaconfig.get_option("logdir")
86    if not enable:
87       return
88
89    logfile= logdir + "/" + get_connect_log_filename()
90
91    if data:
92       data = " " + data
93    else:
94       data = ""
95
96    # prepare the string
97    writeout = str(os.getpid()) + " " + what + data + "\n"
98
99    # try to append to the file
100    try:
101       tempfile = open(logfile, "a")
102       tempfile.write(writeout)
103       tempfile.close()
104    except:
105       pass
106
107
108 def get_transfer_log_filename():
109    hostname = get_hostname()
110    return "transfer-"+hostname
111
112 def log_transfer(function, pid, timestamp, timestampend):
113    """
114    <Purpose>
115       Log the status of a transfer function. this should
116       happen on entry or exit of a function.
117
118    <Arguments>
119       function:
120           the transfer stub ei: coblitz, http, etc
121       pid:
122           the pid that this stub is running in
123       timestamp:
124           a timestamp when this function started transf
125       timestampend:
126           when this function finished transfering
127    """
128    # see if we should log this
129    enable = arizonaconfig.get_option("enablelogging")
130    logdir = arizonaconfig.get_option("logdir")
131    if not enable:
132       return
133
134    logfile= logdir + "/" + get_transfer_log_filename()
135
136    # prepare the string
137    writeout = function + " " + timestamp + " " + timestampend + " " + pid + "\n"
138
139    # try to append to the file
140    try:
141       tempfile = open(logfile, "a")
142       tempfile.write(writeout)
143       tempfile.close()
144    except:
145       pass
146    
147
148 def log_nest(module, function, tag, subtag, info):
149    """
150    <Purpose>
151       Logging support for data collection.
152  
153    <Arguments>
154       module:
155               Calling module name.
156       function:
157               Calling function name. 
158       tag:
159               Main category tag.
160       subtag:
161               Category subtag, or None.
162       info:
163               Information to be logged.      
164
165    <Exceptions>
166       None.
167    
168    <Side Effects>
169       None.
170
171    <Returns>
172       None.
173    """
174    global nodehost, nodeuser
175    
176    # determine current time.  ***DO THIS FIRST***
177    time1 = time.time()
178    time2 = time.gmtime()
179
180    # see if logging is enabled
181    enabled = arizonaconfig.get_option("enablelogging")
182    if not enabled:
183       return
184    
185    try:
186       # collect information
187       if nodehost == None or nodehost == "":
188          hostname = None
189          try:
190             hostname = arizonageneral.gethostname()
191          except:
192             pass
193          if hostname == None:
194             hostname = ""
195             
196       if nodeuser == None or nodeuser == "":
197          try:
198             nodeuser = arizonageneral.getusername()
199          except:
200             nodeuser = ""
201
202       # normalize params
203       if module == None:
204          # should always have a module name, but fix regardless
205          module = ""
206
207       if function == None:
208          # should always have a function name, but fix regardless
209          function = ""
210          
211       if tag == None:
212          # should always have a tag, but fix regardless
213          tag = ""
214       else:
215          tag = tag.strip().lower()
216          
217       if subtag == None:
218          subtag = ""
219       else:
220          subtag = subtag.strip().lower()
221          
222       if info == None:
223          info = ""   
224
225       # build message   
226       mesg = "{time1}" + str(time1) + "{/time1}" + \
227              "{nodehost}" + str(nodehost) + "{/nodehost}" + \
228              "{nodeuser}" + str(nodeuser) + "{/nodeuser}" + \
229              "{chost}" + str(clienthost) + "{/chost}" + \
230              "{cip}" + str(clientip) + "{/cip}" + \
231              "{cport}" + str(clientport) + "{/cport}" + \
232              "{cuser}" + str(clientuser) + "{/cuser}" + \
233              "{module}" + str(module) + "{/module}" + \
234              "{function}" + str(function) + "{/function}" + \
235              "{tag}" + str(tag) + "{/tag}" + \
236              "{sub}" + str(subtag) + "{/sub}" + \
237              "{info}" + str(info) + "{/info}" + \
238              "{pid}" + str(os.getpid()) + "{/pid}"
239              
240       # write to syslog
241       syslog.syslog(arizonareport.NOTICE, mesg)
242    except:
243       # if anything fails, we can't disrupt program operation
244       pass   
245
246
247
248
249
250 def parse_line(line):
251 #   # hour
252 #   i = line.find(":")
253 #   hour = int(line[:i])
254 #   line = line[i + 1:]
255 #
256 #   # minute
257 #   i = line.find(":")
258 #   minute = int(line[:i])
259 #   line = line[i + 1:]
260 #
261 #   # second
262 #   i = line.find(".")
263 #   second = int(line[:i])
264 #   line = line[i + 1:]
265 #   
266 #   # fraction of a second   
267 #   i = line.find(" ")
268 #   fraction = hex(int(line[:i]))[2:]
269 #   line = line[i + 1:]
270 #
271 #   time = hex(3600 * hour + 60 * minute + second)[2:] + "." + fraction
272    i = line.find(" ")
273    time = line[:i]
274    line = line[i + 1:]
275
276    # protocol
277    i = line.find(", proto ")
278    j = line.find(", ", i + 1)
279    protocol = line[i + 8:j]
280    line = line[j + 2:]
281    
282    # length
283    i = line.find(")")
284    length = line[8:i]
285    line = line[i + 2:]
286
287    # source
288    i = line.find(" > ")
289    source = line[:i]
290    line = line[i + 3:]
291    
292    # destination
293    i = line.find(":")
294    destination = line[:i]
295
296    return time + " " + protocol + " " + length + " " + source + " " + destination + "\n"
297
298
299
300
301
302 def compress_packetlog(filename):
303    fi = open(filename)
304    filename_out = filename + "_pr"
305    fo = open(filename_out, "w")
306    for line in fi:
307       try:
308          pruned = parse_line(line)
309       except:
310          pruned = "*" + line
311       fo.write(pruned)
312    fo.close()
313    fi.close()
314    os.system("/usr/bin/bzip2 " + filename_out)
315
316    return filename_out + ".bz2"
317
318
319 def compress_strace(filename):
320    filename_out = filename + "_pr"
321    os.system("/usr/local/stork/bin/filter-strac2 " + filename + " " + filename_out)
322    os.system("/usr/bin/bzip2 " + filename_out)
323
324    return filename_out + ".bz2"
325
326
327 def compress_bzip2(filename):
328    # we use -k to keep the input file to mimic the behavior of the other
329    # compress_ functions.
330    os.system("/usr/bin/bzip2 -k " + filename)
331
332    return filename + ".bz2"
333
334
335
336 # quick hack to back off the strace uploads
337 glo_seeded = False
338 def should_upload_strace():
339     global glo_seeded
340
341     if not glo_seeded:
342         random.seed()
343         glo_seeded = True
344
345     if random.randint(0,24) == 1:
346         return True
347     else:
348         return False
349
350 def upload_logs(suffix, subdir, currentName, compressFunc):
351    print suffix + " start"
352    # get list of files in logdir
353    temp = os.listdir(arizonaconfig.get_option("logdir"))
354
355    print "upload_logs " + str(suffix) + " " + str(subdir) + " " + str(currentName)
356
357    # prune list to packetlog filenames only
358    filelist = []
359    for filename in temp:
360       if filename.endswith(suffix):
361          filelist.append(arizonaconfig.get_option("logdir") + "/" + filename)
362
363    # remove packetlog file named in current.packetlog
364    if currentName:
365       try:
366          temp = open(arizonaconfig.get_option("logdir") + "/" + currentName)
367          current = temp.readline().strip()
368          temp.close()
369          filelist.remove(current)
370       except:
371          pass
372
373    print "  filelist = " + str(filelist)
374
375    # strip unneeded information from packet lines
376    newlist = []
377    for filename in filelist:
378       newName = compressFunc(filename)
379       newlist.append((filename,newName))
380
381    print "  newlist = " + str(newlist)
382
383    # upload packetlogs to repository
384    #if len(filelist) > 0:
385    for f in newlist:
386       #Place the packetlog in the proper folder
387       target = __folder_destination(filelist[0])
388
389       os.system("/usr/bin/ssh -o StrictHostKeyChecking=no -o BatchMode=yes -qi " + arizonaconfig.get_option("idkey") + " " + arizonaconfig.get_option("uploadhost") + " mkdir -p " + arizonaconfig.get_option("uploaddir") + "/" + subdir + "/" + target)
390
391       status = os.system("/usr/bin/scp -o StrictHostKeyChecking=no -Bqi " + \
392                           arizonaconfig.get_option("idkey") + " " + \
393                           f[1] + " " + \
394                           arizonaconfig.get_option("uploadhost") + ":" + arizonaconfig.get_option("uploaddir") + "/" + subdir + "/" + target + " 1> /dev/null 2> /dev/null")
395
396       try:
397          os.remove(f[1])
398       except:
399          pass
400
401       # delete packetlogs
402       if status == 0:
403          #for filename in filelist:
404          try:
405             os.remove(f[0])
406          except:
407             pass
408
409       # delete compressed versions
410       #for filename in newlist:
411       #   try:
412       #      os.remove(filename)
413       #   except:
414       #      pass
415    print suffix + " end"
416
417 def upload_single_log(filename, suffix, subdir, compressFunc):
418    filename = arizonaconfig.get_option("logdir") + "/" + filename
419
420    newname = arizonaconfig.get_option("logdir") + "/" + get_hostname() + \
421                                       "^" + get_username() + \
422                                       "^" + str(time.time()) + suffix
423
424    if not os.path.exists(filename):
425        return
426
427    try:
428        os.rename(filename, newname)
429    except:
430        print "failed to rename " + str(filename) + " to " + str(newname)
431        return
432
433    upload_logs(suffix, subdir, None, compressFunc)
434
435
436
437
438
439 def rotate_logs():
440    """ TODO comment """
441    #try:
442    upload_logs("^packetlog", "packet", "current.packetlog", compress_packetlog)
443    #except:
444    #  pass;
445
446    try:
447       upload_logs("^strac2", "strac2", "current.strac2", compress_strace)
448    except:
449       pass;
450
451    try:
452       upload_single_log(get_transfer_log_filename(), "^transfe2", "transfe2", compress_bzip2)
453    except:
454       pass;
455
456    # get hostname, username, and timestamp
457    hostname = None
458    try:
459       hostname = arizonageneral.gethostname()
460    except:
461       pass
462    if hostname == None:
463       hostname = "unknown_host"
464    try:
465       username = arizonageneral.getusername()
466    except:
467       username = "unknown_user"
468    try:
469       timestamp = str(time.time())
470    except:
471       timestamp = "unknown_time"
472
473    # rotate syslog files
474    os.system("/usr/sbin/logrotate -f /etc/logrotate.d/syslog 2> /dev/null")
475
476    try:
477       # get list of syslog files
478       temp = os.listdir(arizonaconfig.get_option("logdir"))
479
480       # prune list to syslog filenames only (and rename)
481       oldlist = []
482       filelist = []
483       for filename in temp:
484          if (filename.find("messages.") >= 0):
485             oldname = arizonaconfig.get_option("logdir") + "/" + filename
486
487             if oldname.endswith(".bz2"):
488                # this file must be left from a previous attempt to upload
489                # that crashed. We'll add it to the list to upload again.
490                filelist.append(oldname)
491             else:
492                newname = arizonaconfig.get_option("logdir") + "/" + hostname + "^" + username + "^" + timestamp + "^" + filename + "^syslog"
493                try:
494                   os.rename(oldname, newname)
495                except:
496                   pass
497
498                # compress syslog
499                if not newname.endswith(".bz2"):
500                   os.system("/usr/bin/bzip2 " + newname)
501
502                oldlist.append((newname + ".bz2", oldname + ".bz2"))
503                filelist.append(newname + ".bz2")
504
505       ## upload syslogs to repository
506       ##if len(filelist) > 0:
507       #Upload files one at a time
508       
509       for file in filelist:
510          #Place the packetlog in the proper folder
511          target = __folder_destination(file)
512
513          os.system("/usr/bin/ssh -o StrictHostKeyChecking=no -o BatchMode=yes -qi " + arizonaconfig.get_option("idkey") + " " + arizonaconfig.get_option("uploadhost") + " mkdir -p " + arizonaconfig.get_option("uploaddir") + "/syslog/" + target)
514         
515          status = os.system("/usr/bin/scp -o StrictHostKeyChecking=no -Bqi " + arizonaconfig.get_option("idkey") + " " + file + " " + arizonaconfig.get_option("uploadhost") + ":" + arizonaconfig.get_option("uploaddir") + "/syslog/" + target + " 1> /dev/null 2> /dev/null")
516
517          # delete syslogs
518          if status == 0:
519             #for filename in filelist:
520             try:
521                os.remove(file)
522             except:
523                pass
524
525 # Do not restore original name to avoid redundancy, the file will be picked up with this filename
526 #         else:
527 #            # restore error report files back to original names
528 #            for filename in oldlist:
529 #               try:
530 #                  os.rename(filename[0], filename[1])
531 #                  if filename[1].endswith(".bz2"):
532 #                     os.system("/usr/bin/bzip2 -d " + filename[1])
533 #               except:
534 #                  pass
535    except:
536       pass
537
538    if should_upload_strace():
539      try:
540         # filter the strace log
541         try:
542            os.system("/usr/local/stork/bin/filter-strace")
543 #           os.system("/bin/cp /tmp/transfer-`hostname` /tmp/transferpart-`hostname`.`date +%s`")
544         except:
545            pass
546
547         # find any filtered strace files
548         temp = os.listdir(arizonaconfig.get_option("logdir"))
549         filelist = []
550         translist = []
551         for filename in temp:
552            if filename.find("strace") >= 0 and filename.find("raw") < 0:
553               name = arizonaconfig.get_option("logdir") + "/" + filename
554               filelist.append(name)
555            elif filename.find("transferpart") >= 0:
556               name = arizonaconfig.get_option("logdir") + "/" + filename
557               translist.append(name)
558
559         # upload strace reports to repository
560         if len(filelist) > 0:
561            #Place the packetlog in the proper folder
562            target = __folder_destination(filelist[0])
563
564            os.system("/usr/bin/ssh -o StrictHostKeyChecking=no -o BatchMode=yes -qi " + arizonaconfig.get_option("idkey") + " " + arizonaconfig.get_option("uploadhost") + " mkdir -p " + arizonaconfig.get_option("uploaddir") + "/strace/" + target)
565
566            status = os.system("/usr/bin/scp -o StrictHostKeyChecking=no -Bqi " + arizonaconfig.get_option("idkey") + " " + " ".join(translist) + " " + " ".join(filelist) + " " + arizonaconfig.get_option("uploadhost") + ":" + arizonaconfig.get_option("uploaddir") + "/strace/" + target + " 1> /dev/null 2> /dev/null")
567
568            # delete strace reports
569            if status == 0:
570               for filename in filelist:
571                  try:
572                     os.remove(filename)
573                  except:
574                     pass
575               for filename in translist:
576                  try:
577                     os.remove(filename)
578                  except:
579                     pass
580
581      except:
582         pass
583
584
585    try: 
586       # get list of error report files
587       temp = os.listdir(arizonaconfig.get_option("logdir"))
588       
589       # prune list to error report filenames only (and rename)
590       oldlist = []
591       filelist = []
592       for filename in temp:
593          if filename.find(".error.") >= 0:
594             oldname = arizonaconfig.get_option("logdir") + "/" + filename
595             
596             if oldname.endswith(".bz2"):
597                # this file must be left from a previous attempt to upload
598                # that crashed. We'll add it to the list to upload again.
599                filelist.append(oldname)
600             else:
601                newname = arizonaconfig.get_option("logdir") + "/" + hostname + "^" + username + "^" + filename + "^errorreport"
602                
603                #prevent file from being renamed twice
604                if newname.find("errorreport^") > -1:
605                   newname = oldname
606
607                try:
608                   os.rename(oldname, newname)
609                except:
610                   pass
611
612                # compress error report
613                if not newname.endswith(".bz2"):
614                   os.system("/usr/bin/bzip2 " + newname)
615
616                oldlist.append((newname + ".bz2", oldname + ".bz2"))
617                filelist.append(newname + ".bz2")
618
619       # upload error reports to repository
620       if len(filelist) > 0:
621          #Place the packetlog in the proper folder
622          target = __folder_destination(filelist[0])
623
624          os.system("/usr/bin/ssh -o StrictHostKeyChecking=no -o BatchMode=yes -qi " + arizonaconfig.get_option("idkey") + " " + arizonaconfig.get_option("uploadhost") + " mkdir -p " + arizonaconfig.get_option("uploaddir") + "/error/" + target)
625
626          status = os.system("/usr/bin/scp -o StrictHostKeyChecking=no -Bqi " + arizonaconfig.get_option("idkey") + " " + " ".join(filelist) + " " + arizonaconfig.get_option("uploadhost") + ":" + arizonaconfig.get_option("uploaddir") + "/error/" + target + " 1> /dev/null 2> /dev/null")
627
628          # delete error reports
629          if status == 0:
630             for filename in filelist:
631                try:
632                   os.remove(filename)
633                except:
634                   pass   
635          else:
636             # restore error report files back to original names            
637             for filename in oldlist:
638                try:
639                   os.rename(filename[0], filename[1])
640                   if filename[1].endswith(".bz2"):
641                      os.system("/usr/bin/bzip2 -d " + filename[1])
642                except:
643                   pass
644    except:
645       pass   
646
647
648 def __folder_destination(file):
649    l = re.compile("\^([0-9]+)")
650    m = l.search(file)
651    target = ""
652    if(m):
653       number = m.group(1)
654       target = ""
655      
656       number = number[:-3]
657       while len(number) > 3:
658          target = number[-3:] + "/" + target
659          number = number[:-3]
660          
661       target = number + "/" + target
662    return target
663
664 def main():
665    # prepare error reporting tool
666    storkerror.init_error_reporting("storklog.py")
667    
668    # parse command line and options
669    args = arizonaconfig.init_options(module="storklog.py", version="2.0")
670
671    # check for root
672    if os.geteuid() > 0:
673       arizonareport.send_error(0, "You must be root to run this program...")
674       sys.exit(1)
675
676    # grab the storklog mutex. This prevents multiple copies of storklog from
677    # running at the same time.
678    storklogLock = arizonageneral.mutex_lock("storklog", arizonaconfig.get_option("lockdir"))
679    if not storklogLock:
680        arizonareport.send_error(0, "Another copy of storklog is already running...")
681        sys.exit(0)
682
683    # rotate, upload, and delete logs
684    rotate_logs()
685
686
687
688
689
690 if __name__ == "__main__":
691    main()