swapmon.py

   1 #!/usr/bin/python
   2 #
   3 # Swap monitoring daemon. Every 30 seconds, checks process memory
   4 # usage. At 90% utilization, resets the slice that is consuming the
   5 # most physical memory. At 95% utilization, reboots the machine to
   6 # avoid a crash.
   7 #
   8 # Mark Huang <mlhuang@cs.princeton.edu>
   9 # Andy Bavier <acb@cs.princeton.edu>
  10 # Faiyaz Ahmed <faiyaza@cs.princeton.edu>
  11 # Copyright (C) 2004-2006 The Trustees of Princeton University
  12 #
  13 # $Id: swapmon.py,v 1.5 2006/05/09 03:23:57 mlhuang Exp $
  14 #
  15
  16 import syslog
  17 import os
  18 import sys
  19 import getopt
  20 import re
  21 import pickle
  22 import socket
  23 import time
  24
  25 # util-vserver/python/vserver.py allows us to control slices directly
  26 # from Python
  27 from vserver import VServer
  28
  29 # bwlimit exports a few useful functions like run(), get_xid(), and get_slice()
  30 import bwlimit
  31
  32 # Utility functions
  33 from pl_mom import *
  34
  35 # Defaults
  36 debug = False
  37 verbose = 0
  38 datafile = "/var/lib/misc/swapmon.dat"
  39
  40 # Seconds between process analysis
  41 period = 30
  42
  43 # Minimum change in swap utilization over 30 seconds that will trigger
  44 # early process analysis.
  45 change_thresh = 5
  46
  47 # Swap utilization at which the largest consumer of physical memory is reset
  48 reset_thresh = 80
  49
  50 # Swap utilization at which the machine is rebooted
  51 reboot_thresh = 95
  52
  53 # Time to wait before checking slice again after reset
  54 reset_timeout = 15
  55
  56 # Number of strikes before killing (strike, strike, kill)
  57 kill_thresh = 2
  58
  59 # Time to wait before removing slice from kill queue (probation)
  60 kill_timeout = 120
  61
  62 # Don't email the same message more than once in the same emailtimeout interval
  63 email_timeout = 1800
  64
  65 # Minimum physical memory utilization to be considered the largest consumer
  66 min_thresh = 10
  67
  68 # System slices that should not be reset (regexps)
  69 system_slices = ['root', PLC_SLICE_PREFIX + '_']
  70
  71 # Message sent after a critical reboot
  72 rebooted_subject = "pl_mom rebooted %(hostname)s"
  73 rebooted_body = \
  74 """
  75 Sometime before %(date)s, swap space was
  76 nearly exhausted on %(hostname)s, so pl_mom rebooted it.
  77
  78 Slices active prior to reboot are listed below. Memory usage
  79 statistics are not entirely accurate due to threading.
  80
  81 %(table)s
  82
  83 %(date)s %(hostname)s reboot
  84 """.lstrip()
  85
  86 # Message sent after a hog is reset
  87 reset_subject = "pl_mom reset slice %(slice)s on %(hostname)s"
  88 reset_body = \
  89 """
  90 Sometime before %(date)s, swap space was
  91 nearly exhausted on %(hostname)s.
  92
  93 Slice %(slice)s was reset since it was the largest consumer of
  94 physical memory at %(rss)s (%(percent)4.1f%%).
  95
  96 Please reply to this message explaining the nature of your experiment,
  97 and what you are doing to address the problem.
  98
  99 %(slice)s processes prior to reset:
 100
 101 %(table)s
 102
 103 %(date)s %(hostname)s reset %(slice)s
 104 """.lstrip()
 105
 106 # Message sent to system slices that should not be reset
 107 alarm_subject = "pl_mom alarm slice %(slice)s on %(hostname)s"
 108 alarm_body = \
 109 """
 110 Sometime before %(date)s, swap space was
 111 nearly exhausted on %(hostname)s.
 112
 113 System slice %(slice)s was the largest consumer of physical memory at
 114 %(rss)s (%(percent)4.1f%%). It was not reset, but please verify its
 115 behavior.
 116
 117 %(slice)s processes prior to alarm:
 118
 119 %(table)s
 120
 121 %(date)s %(hostname)s alarm %(slice)s
 122 """.lstrip()
 123
 124 # Message sent after a slice has been killed
 125 kill_subject = "pl_mom killed slice %(slice)s on %(hostname)s"
 126 kill_body = \
 127 """
 128 Sometime before %(date)s, swap space was
 129 nearly exhausted on %(hostname)s.
 130
 131 Slice %(slice)s was killed since it was the largest consumer of
 132 physical memory at %(rss)s (%(percent)4.1f%%) after repeated restarts.
 133
 134 Please reply to this message explaining the nature of your experiment,
 135 and what you are doing to address the problem.
 136
 137 %(slice)s processes prior to reset:
 138
 139 %(table)s
 140
 141 %(date)s %(hostname)s reset %(slice)s
 142 """.lstrip()
 143
 144
 145
 146 class Reset:
 147         """
 148         Keeps track of state information for resets and kills
 149
 150         resettimeleft - timeout before checking for next reset
 151         resetcount - number of strikes
 152         killtimeleft - time out before removing from kill queue
 153         {kill,reset}mail - Time of last email
 154         kill - State of kill.  If slice is already being killed, wait before retry.
 155         """
 156
 157         def __init__(self,name):
 158                 self.name = name
 159                 self.resettimeleft = reset_timeout
 160                 self.resetcount = 0
 161                 self.resetmail = 0
 162                 self.kill = False
 163                 self.killtimeleft = kill_timeout
 164                 self.killmail = 0
 165
 166         def __repr__(self):
 167                 return self.name
 168
 169         def update(self):
 170                 # Count down for next check of reset slice.
 171                 if self.resettimeleft > 0:
 172                         self.resettimeleft -= 1
 173                         if debug and verbose:
 174                                 print "%s has %s seconds in probation" \
 175                                         %(self.name, self.killtimeleft)
 176                 if self.killtimeleft > 0:
 177                         # Count down kill probation timer (killtimeleft)
 178                         self.killtimeleft -= 1
 179                         if self.killtimeleft == 1:
 180                                 print "%s is out of probation" % self.name
 181                 else:
 182                         # Once out of probation period (killtimeleft), remove strikes
 183                         self.resetcount = 0
 184                         self.kill = False
 185
 186
 187         # Check to see if a slice needs to be killed.  If it has rules more than kill_thresh in
 188         # the probation period (kill_timeout) send an email, kill the slice.
 189         def checkkill(self,params):
 190                 if self.killtimeleft > 0 and self.resetcount >= kill_thresh and \
 191                 self.kill == False:
 192                         self.kill = True
 193                         if debug:
 194                                 print kill_subject % params
 195                                 print kill_body % params
 196                         try:
 197                                 self.pid = os.fork()
 198                                 if self.pid == 0:
 199                                         print "Slice %s is being killed." % self.name
 200                                         vserver = VServer(self.name)
 201                                         vserver.stop()
 202                                         os._exit(0)
 203                         except Exception, err:
 204                                 print "Warning: Exception received while killing slice %s: %s" % self.name, err
 205                         if (time.time() - self.killmail) > email_timeout:
 206                                 slicemail(self.name, kill_subject % params, kill_body % params)
 207                                 print "Sending KILL email for slice %s" % self.name
 208                                 self.killmail = time.time()
 209                         return True
 210                 return False
 211
 212         # Reset slice after checking to see if slice is out of timeout.
 213         # Increment resetcount, check to see if larger than kill_thresh.
 214         def reset(self, params):
 215                 # If its the first reset or if its been reset before
 216                 # and we are out of the reset timeout.
 217                 if self.resetcount == 0 or self.resettimeleft == 0:
 218                         # Do we need to kill this slice?  Check history first.
 219                         if self.checkkill(params):
 220                                 return
 221                         # Update counters
 222                         self.resetcount += 1
 223                         self.killtimeleft = kill_timeout
 224                         self.resettimeleft = reset_timeout
 225                         print "%s has %s seconds to die and has been reset %s times" \
 226                                 %(self.name, self.resettimeleft, self.resetcount)
 227                         if debug:
 228                                 print reset_subject % params
 229                                 print reset_body % params
 230                         try:
 231                                 pid = os.fork()
 232                                 if pid == 0:
 233                                         print "Resetting slice " + self.name
 234                                         vserver = VServer(self.name)
 235                                         vserver.stop()
 236                                         vserver.start(wait = False)
 237                                         os._exit(0)
 238                         except Exception, err:
 239                                 print "Warning: Exception received while resetting slice %s:" \
 240                                         % self.name, err
 241                         if (time.time() - self.resetmail) > email_timeout:
 242                                 slicemail(self.name, reset_subject % params, reset_body % params)
 243                                 print "Sending Reset email for slice %s" % self.name
 244                                 self.resetmail = time.time()
 245
 246
 247 def usage():
 248     print """
 249 Usage: %s [OPTIONS]...
 250
 251 Options:
 252         -d, --debug             Enable debugging (default: %s)
 253         -v, --verbose           Increase verbosity level (default: %d)
 254         -f, --file=FILE         Data file (default: %s)
 255         -s, --slice=SLICE       Constrain monitoring to these slices (default: all)
 256         -p, --period=SECONDS    Seconds between normal process analysis (default: %s)
 257         --reset-thresh=PERCENT  Swap utilization at which slice reset is attempted
 258         --reboot-thresh=PERCENT Swap utilization at which the machine is rebooted
 259         --min-thresh=PERCENT    Minimum physical memory utilization to be considered a hog
 260         --system-slice=SLICE    System slice that should not be reset
 261         --status                Print memory usage statistics and exit
 262         -h, --help              This message
 263 """.lstrip() % (sys.argv[0], debug, verbose, datafile, format_period(period))
 264
 265 def slicestat(names = None):
 266     """
 267     Get status of specified slices (if names is None or empty, all
 268     slices). vsize and rss are in KiB. Returns
 269
 270     {xid: {'xid': slice_id,
 271            'name': slice_name,
 272            'procs': [{'pid': pid, 'xid': slice_id, 'user', username, 'cmd': command,
 273                       'vsize': virtual_kib, 'rss': physical_kib,
 274                       'pcpu': cpu_percent, 'pmem': mem_percent}]
 275            'vsize': total_virtual_kib,
 276            'rss': total_physical_kib}}
 277     """
 278
 279     # Mandatory fields. xid is a virtual field inserted by vps. Make
 280     # sure cmd is last so that it does not get truncated
 281     # automatically.
 282     fields = ['pid', 'xid', 'user', 'vsize', 'rss', 'pcpu', 'pmem', 'cmd']
 283
 284     # vps inserts xid after pid in the output, but ps doesn't know
 285     # what the field means.
 286     ps_fields = list(fields)
 287     ps_fields.remove('xid')
 288
 289     slices = {}
 290
 291     # Eat the header line. vps depends on the header to figure out
 292     # which column is the PID column, so we can't just tell ps not to
 293     # print it.
 294     for line in bwlimit.run("/usr/sbin/vps -e -o " + ",".join(ps_fields))[1:]:
 295         # Chomp newline
 296         line = line.strip()
 297
 298         # Replace "0 MAIN" and "1 ALL_PROC" (the special monikers that
 299         # vps uses to denote the root context and the "all contexts"
 300         # context) with "0" so that we can just split() on whitespace.
 301         line = line.replace("0 MAIN", "0").replace("1 ALL_PROC", "0")
 302
 303         # Represent process as a dict of fields
 304         values = line.split(None, len(fields) - 1)
 305         if len(values) != len(fields):
 306             continue
 307         proc = dict(zip(fields, values))
 308
 309         # Convert ints and floats
 310         for field in proc:
 311             try:
 312                 proc[field] = int(proc[field])
 313             except ValueError:
 314                 try:
 315                     proc[field] = float(proc[field])
 316                 except ValueError:
 317                     pass
 318
 319         # vps sometimes prints ERR instead of a context ID if it
 320         # cannot identify the context of an orphaned (usually dying)
 321         # process. Skip these processes.
 322         if type(proc['xid']) != int:
 323             continue
 324
 325         # Assign (pl_)sshd processes to slice instead of root
 326         m = re.search(r"sshd: ([a-zA-Z_]+)", proc['cmd'])
 327         if m is not None:
 328             xid = bwlimit.get_xid(m.group(1))
 329             if xid is not None:
 330                 proc['xid'] = xid
 331
 332         name = bwlimit.get_slice(proc['xid'])
 333         if name is None:
 334             # Orphaned (not associated with a slice) class
 335             name = "%d?" % proc['xid']
 336
 337         # Monitor only the specified slices
 338         if names and name not in names:
 339             continue
 340
 341         # Additional overhead calculations from slicestat
 342
 343         # Include 12 KiB of process overhead =
 344         # 4 KiB top-level page table +
 345         # 4 KiB kernel structure +
 346         # 4 KiB basic page table
 347         proc['rss'] += 12
 348
 349         # Include additional page table overhead
 350         if proc['vsize'] > 4096:
 351             proc['rss'] += 4 * ((proc['vsize'] - 1) / 4096)
 352
 353         if slices.has_key(proc['xid']):
 354             slice = slices[proc['xid']]
 355         else:
 356             slice = {'xid': proc['xid'], 'name': name, 'procs': [], 'vsize': 0, 'rss': 0}
 357
 358         slice['procs'].append(proc)
 359         slice['vsize'] += proc['vsize']
 360         slice['rss'] += proc['rss']
 361
 362         slices[proc['xid']] = slice
 363
 364     return slices
 365
 366 def memtotal():
 367     """
 368     Returns total physical memory on the system in KiB.
 369     """
 370
 371     meminfo = open("/proc/meminfo", "r")
 372     line = meminfo.readline()
 373     meminfo.close()
 374     if line[0:8] == "MemTotal":
 375         # MemTotal: 255396 kB
 376         (name, value, kb) = line.split()
 377         return int(value)
 378
 379     return 0
 380
 381 def swap_used():
 382     """
 383     Returns swap utilization on the system as a whole percentage (0-100).
 384     """
 385
 386     total_swap = 0
 387     total_used = 0
 388
 389     try:
 390         swaps = open("/proc/swaps", "r")
 391         # Eat header line
 392         lines = swaps.readlines()[1:]
 393         swaps.close()
 394         for line in lines:
 395             # /dev/mapper/planetlab-swap partition 1048568 3740 -1
 396             (filename, type, size, used, priority) = line.strip().split()
 397             try:
 398                 total_swap += int(size)
 399                 total_used += int(used)
 400             except ValueEror, err:
 401                 pass
 402     except (IOError, KeyError), err:
 403         pass
 404
 405     return 100 * total_used / total_swap
 406
 407 def summary(names = None, total_rss = memtotal()):
 408     """
 409     Return a summary of memory usage by slice.
 410     """
 411     slicelist = slicestat(names).values()
 412     slicelist.sort(lambda a, b: b['rss'] - a['rss'])
 413
 414     table = "%-20s%10s%24s\n\n" % ("Slice", "Processes", "Memory Usage")
 415     for slice in slicelist:
 416         table += "%-20s%10d%16s (%4.1f%%)\n" % \
 417                  (slice['name'], len(slice['procs']),
 418                   format_bytes(slice['rss'] * 1024, si = False),
 419                   100. * slice['rss'] / total_rss)
 420
 421     return table
 422
 423 def main():
 424     # Defaults
 425     global debug, verbose, datafile
 426     global period, change_thresh, reset_thresh, reboot_thresh, min_thresh, system_slices
 427     # All slices
 428     names = []
 429
 430     try:
 431         longopts = ["debug", "verbose", "file=", "slice=", "status", "help"]
 432         longopts += ["period=", "reset-thresh=", "reboot-thresh=", "min-thresh=", "system-slice="]
 433         (opts, argv) = getopt.getopt(sys.argv[1:], "dvf:s:ph", longopts)
 434     except getopt.GetoptError, err:
 435         print "Error: " + err.msg
 436         usage()
 437         sys.exit(1)
 438
 439     for (opt, optval) in opts:
 440         if opt == "-d" or opt == "--debug":
 441             debug = True
 442         elif opt == "-v" or opt == "--verbose":
 443             verbose += 1
 444         elif opt == "-f" or opt == "--file":
 445             datafile = optval
 446         elif opt == "-s" or opt == "--slice":
 447             names.append(optval)
 448         elif opt == "-p" or opt == "--period":
 449             period = int(optval)
 450         elif opt == "--change-thresh":
 451             change_thresh = int(optval)
 452         elif opt == "--reset-thresh":
 453             reset_thresh = int(optval)
 454         elif opt == "--reboot-thresh":
 455             reboot_thresh = int(optval)
 456         elif opt == "--min-thresh":
 457             min_thresh = int(optval)
 458         elif opt == "--system-slice":
 459             system_slices.append(optval)
 460         elif opt == "--status":
 461             print summary(names)
 462             sys.exit(0)
 463         else:
 464             usage()
 465             sys.exit(0)
 466
 467     # Check if we are already running
 468     writepid("swapmon")
 469
 470     if not debug:
 471         daemonize()
 472         # Rewrite PID file
 473         writepid("swapmon")
 474         # Redirect stdout and stderr to syslog
 475         syslog.openlog("swapmon")
 476         sys.stdout = sys.stderr = Logger()
 477
 478     # Get total physical memory
 479     total_rss = memtotal()
 480
 481     try:
 482         f = open(datafile, "r+")
 483         if verbose:
 484             print "Loading %s" % datafile
 485         (version, slices) = pickle.load(f)
 486         f.close()
 487         # Check version of data file
 488         if version != "$Id: swapmon.py,v 1.5 2006/05/09 03:23:57 mlhuang Exp $":
 489             print "Not using old version '%s' data file %s" % (version, datafile)
 490             raise Exception
 491
 492         params = {'hostname': socket.gethostname(),
 493                   'date': time.asctime(time.gmtime()) + " GMT",
 494                   'table': summary(total_rss)}
 495
 496         if debug:
 497             print rebooted_subject % params
 498             print rebooted_body % params
 499         else:
 500             slicemail(None, rebooted_subject % params, rebooted_body % params)
 501
 502         # Delete data file
 503         os.unlink(datafile)
 504     except Exception:
 505         version = "$Id: swapmon.py,v 1.5 2006/05/09 03:23:57 mlhuang Exp $"
 506         slices = {}
 507
 508     # Query process table every 30 seconds, or when a large change in
 509     # swap utilization is detected.
 510     timer = period
 511     last_used = None
 512     used = None
 513
 514     # System slices that we have warned but could not reset
 515     warned = []
 516
 517     # Slices that were reset
 518     resetlist = {}
 519
 520     while True:
 521         used = swap_used()
 522
 523         for resetslice in resetlist.keys():
 524                 resetlist[resetslice].update()
 525
 526         if last_used is None:
 527             last_used = used
 528         if verbose:
 529             print "%d%% swap consumed" % used
 530
 531         if used >= reboot_thresh:
 532             # Dump slice state before rebooting
 533             if verbose:
 534                 print "Saving %s" % datafile
 535             f = open(datafile, "w")
 536             pickle.dump((version, slices), f)
 537             f.close()
 538
 539             # Goodbye, cruel world
 540             print "%d%% swap consumed, rebooting" % used
 541             if not debug:
 542                 bwlimit.run("/bin/sync; /sbin/reboot -f")
 543
 544         elif used >= reset_thresh:
 545             # Try and find a hog
 546             slicelist = slices.values()
 547             slicelist.sort(lambda a, b: b['rss'] - a['rss'])
 548             for slice in slicelist:
 549                 percent = 100. * slice['rss'] / total_rss
 550
 551                 if percent < min_thresh:
 552                     continue
 553
 554                 print "%d%% swap consumed, slice %s is using %s (%d%%) of memory" % \
 555                       (used,
 556                        slice['name'],
 557                        format_bytes(slice['rss'] * 1024, si = False),
 558                        percent)
 559
 560                 slice['procs'].sort(lambda a, b: b['rss'] - a['rss'])
 561
 562                 table = "%5s %10s %10s %4s %4s %s\n\n" % ("PID", "VIRT", "RES", '%CPU', '%MEM', 'COMMAND')
 563                 for proc in slice['procs']:
 564                     table += "%5s %10s %10s %4.1f %4.1f %s\n" % \
 565                              (proc['pid'],
 566                               format_bytes(proc['vsize'] * 1024, si = False),
 567                               format_bytes(proc['rss'] * 1024, si = False),
 568                               proc['pcpu'], proc['pmem'], proc['cmd'])
 569
 570                 params = {'hostname': socket.gethostname(),
 571                           'date': time.asctime(time.gmtime()) + " GMT",
 572                           'table': table,
 573                           'slice': slice['name'],
 574                           'rss': format_bytes(slice['rss'] * 1024, si = False),
 575                           'percent': percent}
 576
 577                 # Match slice name against system slice patterns
 578                 is_system_slice = filter(None, [re.match(pattern, slice['name']) for pattern in system_slices])
 579
 580                 if is_system_slice and params['rss'] > 100:
 581                     # Do not reset system slices, just warn once
 582                     if slice['name'] not in warned:
 583                         warned.append(slice['name'])
 584                         if debug:
 585                             print alarm_subject % params
 586                             print alarm_body % params
 587                         else:
 588                             print "Warning slice " + slice['name']
 589                             slicemail(slice['name'], alarm_subject % params, alarm_body % params)
 590                 else:
 591                         # Reset slice
 592                         if not resetlist.has_key(slice['name']):
 593                                 resetlist[slice['name']] = Reset(slice['name'])
 594                         resetlist[slice['name']].reset(params)
 595
 596         elif timer <= 0 or used >= (last_used + change_thresh):
 597             if used >= (last_used + change_thresh):
 598                 print "%d%% swap consumed, %d%% in last %d seconds" % \
 599                       (used, used - last_used, period - timer)
 600             # Get slice state
 601             slices = slicestat(names)
 602             # Reset timer
 603             timer = period
 604             # Keep track of large changes in swap utilization
 605             last_used = used
 606
 607         timer -= 1
 608         time.sleep(1)
 609
 610     removepid("swapmon")
 611
 612 if __name__ == '__main__':
 613     main()