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