fcm make: report memory used by shell commands

[steoxley]

As well as how long a particular command takes to complete, it is also useful to know how much memory it takes.

fcm currently does not handle this therefore we use wrapper scripts and post processessing of the fcm-make.log to achieve this goal.

e.g. fcm config files become:

var_x86_64_ifort_opt.cfg:$FCM_COMMAND_WRAPPER{?} =
var_x86_64_ifort_opt.cfg:$ar = $FCM_COMMAND_WRAPPER ar
var_x86_64_ifort_opt.cfg:$cc = $FCM_COMMAND_WRAPPER gcc
var_x86_64_ifort_opt.cfg:$fc = $FCM_COMMAND_WRAPPER ifort-13.1

where FCM_COMMAND_WRAPPER is hpmcount-m on our Power 7, and time-m on the Linux desktop platform.

File: hpmcount-m

#!/bin/ksh
hpmcount_out=$(mktemp)
COMMAND="$@"
hpmcount -o $hpmcount_out $COMMAND
RC=$?
grep "Maximum resident set size" ${hpmcount_out}_* | sed "s|$| : $COMMAND|"
rm ${hpmcount_out}_*
return $RC

File: time-m

#!/bin/ksh
time_out=$(mktemp)
COMMAND="$@"
time -f "Maximum resident set size (kbytes * 4): %M : $COMMAND" -o $time_out $COMMAND
RC=$?
cat $time_out
rm $time_out
return $RC

From within a rose environment:

command scripting = "fcm-make"

File: fcm-make

#!/bin/ksh
rose task-run
RC=$?
fcm-make-log $CYLC_SUITE_SHARE_DIR/$CYLC_TASK_NAME/.fcm-make/log
RC2=$?
if [[ $RC != 0 ]]; then
   return $RC
fi
return $RC2

File: fcm-make-log

#!/usr/bin/env python2.7

import sys

DEFAULT_LIST_LENGTH = 10


def main(argv):
    """
Process fcm-make.log files:
    Optionally extracts all stderr and selected information relating to memory
    intensive shell commands and longest running shell commands.
    """

    import argparse

    from argparse import ArgumentParser, RawTextHelpFormatter, \
        ArgumentDefaultsHelpFormatter

    class Formatter (RawTextHelpFormatter, ArgumentDefaultsHelpFormatter):
        pass

    parser = ArgumentParser(formatter_class=Formatter,
                            description=main.__doc__)
    parser.add_argument(
        'fcm_log_file', nargs='?', type=argparse.FileType('r'),
        default=sys.stdin, help=
        'Location of fcm-make-log file to process - takes from stdin '
        'if not present')
    parser.add_argument(
        '--[no-]extract-stderr', dest='extract_stderr',
        action='store_true', default='store_true', help=
        'Extract stderr')
    parser.add_argument(
        '--no-extract-stderr', dest='extract_stderr',
        action='store_false', help=argparse.SUPPRESS)
    parser.add_argument(
        '--memory', type=int, default=DEFAULT_LIST_LENGTH, help=
        'Display top MEMORY intensive commands. Set to 0 to disable.')
    parser.add_argument(
        '--longest', type=int, default=DEFAULT_LIST_LENGTH, help=
        'Display top LONGEST commands. Set to 0 to disable.')

    args = parser.parse_args()
    time_list = []
    mem_list = []

    for line in args.fcm_log_file.readlines():
        if args.extract_stderr and "[>>&2]" in line:
            sys.stderr.write(line)
        if "[info] shell(" in line:
            split_line = line.split()
            time_list.append(split_line[2].replace(')', '') + " " +
                             " ".join(split_line[3:]) + "\n")
        if "Maximum resident set size  " in line:
            split_line = line.split()
            mem_list.append(split_line[6] + " " + split_line[7] +
                            " ".join(split_line[8:]) + "\n")
        if "Maximum resident set size (kbytes * 4)" in line:
            split_line = line.split()
            mem_list.append(str(int(split_line[8])/4) + " " +
                            split_line[5][1: 7] +
                            " ".join(split_line[9:]) + "\n")
        if "Maximum resident set size (kbytes)" in line:
            split_line = line.split()
            mem_list.append(split_line[6] + " " + split_line[5][1: 7] +
                            " ".join(split_line[7:]) + "\n")

    if args.memory > 0:
        print("Top " + str(args.memory) + " memory intensive commands:")
        sorted_list = sorted(mem_list, key=lambda x: int(x.split()[0]),
                             reverse=True)
        for line in sorted_list[:args.memory]:
            sys.stdout.write(line)
        print

    if args.longest > 0:
        print("Top " + str(args.longest) + " longest commands:")
        sorted_list = sorted(time_list, key=lambda x: float(x.split()[0]),
                             reverse=True)
        for line in sorted_list[:args.longest]:
            sys.stdout.write(line)

if __name__ == '__main__':
    main(sys.argv[1:])

The python script above also addresses some aspects of #7.

Ideally most of the above functionality would be included in fcm. If we were to do this, the solution may be related to how we deal with different architectures in "rose mpi-launch".

Note that the above also addresses a known bug with Linux "time" returning 4 times as much memory as truth on our systems.