xref: /openbmc/openbmc-test-automation/lib/gen_print.py (revision aca557110becf3f4d45391b6f70d0f52f1046f4e)
1#!/usr/bin/env python
2
3r"""
4This module provides many valuable print functions such as sprint_var,
5sprint_time, sprint_error, sprint_call_stack.
6"""
7
8import sys
9import os
10import time
11import inspect
12import re
13import grp
14import socket
15import argparse
16import __builtin__
17import logging
18import collections
19
20try:
21    from robot.utils import DotDict
22except ImportError:
23    pass
24
25import gen_arg as ga
26
27# Setting these variables for use both inside this module and by programs
28# importing this module.
29pgm_dir_path = sys.argv[0]
30pgm_name = os.path.basename(pgm_dir_path)
31pgm_dir_name = re.sub("/" + pgm_name, "", pgm_dir_path) + "/"
32
33
34# Some functions (e.g. sprint_pgm_header) have need of a program name value
35# that looks more like a valid variable name.  Therefore, we'll swap odd
36# characters like "." out for underscores.
37pgm_name_var_name = pgm_name.replace(".", "_")
38
39# Initialize global values used as defaults by print_time, print_var, etc.
40col1_indent = 0
41
42# Calculate default column width for print_var functions based on environment
43# variable settings.  The objective is to make the variable values line up
44# nicely with the time stamps.
45col1_width = 29
46if 'NANOSECONDS' in os.environ:
47    NANOSECONDS = os.environ['NANOSECONDS']
48else:
49    NANOSECONDS = 0
50
51if NANOSECONDS == "1":
52    col1_width = col1_width + 7
53
54if 'SHOW_ELAPSED_TIME' in os.environ:
55    SHOW_ELAPSED_TIME = os.environ['SHOW_ELAPSED_TIME']
56else:
57    SHOW_ELAPSED_TIME = 0
58
59if SHOW_ELAPSED_TIME == "1":
60    if NANOSECONDS == "1":
61        col1_width = col1_width + 14
62    else:
63        col1_width = col1_width + 7
64
65# Initialize some time variables used in module functions.
66start_time = time.time()
67sprint_time_last_seconds = start_time
68
69try:
70    # The user can set environment variable "GEN_PRINT_DEBUG" to get debug
71    # output from this module.
72    gen_print_debug = int(os.environ['GEN_PRINT_DEBUG'])
73except KeyError:
74    gen_print_debug = 0
75
76
77###############################################################################
78def sprint_func_name(stack_frame_ix=None):
79
80    r"""
81    Return the function name associated with the indicated stack frame.
82
83    Description of arguments:
84    stack_frame_ix                  The index of the stack frame whose
85                                    function name should be returned.  If the
86                                    caller does not specifiy a value, this
87                                    function will set the value to 1 which is
88                                    the index of the caller's stack frame.  If
89                                    the caller is the wrapper function
90                                    "print_func_name", this function will bump
91                                    it up by 1.
92    """
93
94    # If user specified no stack_frame_ix, we'll set it to a proper default
95    # value.
96    if stack_frame_ix is None:
97        func_name = sys._getframe().f_code.co_name
98        caller_func_name = sys._getframe(1).f_code.co_name
99        if func_name[1:] == caller_func_name:
100            stack_frame_ix = 2
101        else:
102            stack_frame_ix = 1
103
104    func_name = sys._getframe(stack_frame_ix).f_code.co_name
105
106    return func_name
107
108###############################################################################
109
110
111# get_arg_name is not a print function per se.  I have included it in this
112# module because it is used by sprint_var which is found in this module.
113###############################################################################
114def get_arg_name(var,
115                 arg_num=1,
116                 stack_frame_ix=1):
117
118    r"""
119    Return the "name" of an argument passed to a function.  This could be a
120    literal or a variable name.
121
122    Description of arguements:
123    var                             The variable whose name you want returned.
124    arg_num                         The arg number (1 through n) whose name
125                                    you wish to have returned.  This value
126                                    should not exceed the number of arguments
127                                    allowed by the target function.
128    stack_frame_ix                  The stack frame index of the target
129                                    function.  This value must be 1 or
130                                    greater.  1 would indicate get_arg_name's
131                                    stack frame.  2 would be the caller of
132                                    get_arg_name's stack frame, etc.
133
134    Example 1:
135
136    my_var = "mike"
137    var_name = get_arg_name(my_var)
138
139    In this example, var_name will receive the value "my_var".
140
141    Example 2:
142
143    def test1(var):
144        # Getting the var name of the first arg to this function, test1.
145        # Note, in this case, it doesn't matter what you pass as the first arg
146        # to get_arg_name since it is the caller's variable name that matters.
147        dummy = 1
148        arg_num = 1
149        stack_frame = 2
150        var_name = get_arg_name(dummy, arg_num, stack_frame)
151
152    # Mainline...
153
154    another_var = "whatever"
155    test1(another_var)
156
157    In this example, var_name will be set to "another_var".
158
159    """
160
161    # Note: I wish to avoid recursion so I refrain from calling any function
162    # that calls this function (i.e. sprint_var, valid_value, etc.).
163
164    # The user can set environment variable "GET_ARG_NAME_DEBUG" to get debug
165    # output from this function.
166    local_debug = int(os.environ.get('GET_ARG_NAME_DEBUG', 0))
167    # In addition to GET_ARG_NAME_DEBUG, the user can set environment
168    # variable "GET_ARG_NAME_SHOW_SOURCE" to have this function include source
169    # code in the debug output.
170    local_debug_show_source = int(
171        os.environ.get('GET_ARG_NAME_SHOW_SOURCE', 0))
172
173    if arg_num < 1:
174        print_error("Programmer error - Variable \"arg_num\" has an invalid" +
175                    " value of \"" + str(arg_num) + "\".  The value must be" +
176                    " an integer that is greater than 0.\n")
177        # What is the best way to handle errors?  Raise exception?  I'll
178        # revisit later.
179        return
180    if stack_frame_ix < 1:
181        print_error("Programmer error - Variable \"stack_frame_ix\" has an" +
182                    " invalid value of \"" + str(stack_frame_ix) + "\".  The" +
183                    " value must be an integer that is greater than or equal" +
184                    " to 1.\n")
185        return
186
187    if local_debug:
188        debug_indent = 2
189        print("")
190        print_dashes(0, 120)
191        print(sprint_func_name() + "() parms:")
192        print_varx("var", var, 0, debug_indent)
193        print_varx("arg_num", arg_num, 0, debug_indent)
194        print_varx("stack_frame_ix", stack_frame_ix, 0, debug_indent)
195        print("")
196        print_call_stack(debug_indent, 2)
197
198    for count in range(0, 2):
199        try:
200            frame, filename, cur_line_no, function_name, lines, index = \
201                inspect.stack()[stack_frame_ix]
202        except IndexError:
203            print_error("Programmer error - The caller has asked for" +
204                        " information about the stack frame at index \"" +
205                        str(stack_frame_ix) + "\".  However, the stack" +
206                        " only contains " + str(len(inspect.stack())) +
207                        " entries.  Therefore the stack frame index is out" +
208                        " of range.\n")
209            return
210        if filename != "<string>":
211            break
212        # filename of "<string>" may mean that the function in question was
213        # defined dynamically and therefore its code stack is inaccessible.
214        # This may happen with functions like "rqprint_var".  In this case,
215        # we'll increment the stack_frame_ix and try again.
216        stack_frame_ix += 1
217        if local_debug:
218            print("Adjusted stack_frame_ix...")
219            print_varx("stack_frame_ix", stack_frame_ix, 0, debug_indent)
220
221    called_func_name = sprint_func_name(stack_frame_ix)
222
223    module = inspect.getmodule(frame)
224
225    # Though I would expect inspect.getsourcelines(frame) to get all module
226    # source lines if the frame is "<module>", it doesn't do that.  Therefore,
227    # for this special case, I will do inspect.getsourcelines(module).
228    if function_name == "<module>":
229        source_lines, source_line_num =\
230            inspect.getsourcelines(module)
231        line_ix = cur_line_no - source_line_num - 1
232    else:
233        source_lines, source_line_num =\
234            inspect.getsourcelines(frame)
235        line_ix = cur_line_no - source_line_num
236
237    if local_debug:
238        print("\n  Variables retrieved from inspect.stack() function:")
239        print_varx("frame", frame, 0, debug_indent + 2)
240        print_varx("filename", filename, 0, debug_indent + 2)
241        print_varx("cur_line_no", cur_line_no, 0, debug_indent + 2)
242        print_varx("function_name", function_name, 0, debug_indent + 2)
243        print_varx("lines", lines, 0, debug_indent + 2)
244        print_varx("index", index, 0, debug_indent + 2)
245        print_varx("source_line_num", source_line_num, 0, debug_indent)
246        print_varx("line_ix", line_ix, 0, debug_indent)
247        if local_debug_show_source:
248            print_varx("source_lines", source_lines, 0, debug_indent)
249        print_varx("called_func_name", called_func_name, 0, debug_indent)
250
251    # Get a list of all functions defined for the module.  Note that this
252    # doesn't work consistently when _run_exitfuncs is at the top of the stack
253    # (i.e. if we're running an exit function).  I've coded a work-around
254    # below for this deficiency.
255    all_functions = inspect.getmembers(module, inspect.isfunction)
256
257    # Get called_func_id by searching for our function in the list of all
258    # functions.
259    called_func_id = None
260    for func_name, function in all_functions:
261        if func_name == called_func_name:
262            called_func_id = id(function)
263            break
264    # NOTE: The only time I've found that called_func_id can't be found is
265    # when we're running from an exit function.
266
267    # Look for other functions in module with matching id.
268    aliases = set([called_func_name])
269    for func_name, function in all_functions:
270        if func_name == called_func_name:
271            continue
272        func_id = id(function)
273        if func_id == called_func_id:
274            aliases.add(func_name)
275
276    # In most cases, my general purpose code above will find all aliases.
277    # However, for the odd case (i.e. running from exit function), I've added
278    # code to handle pvar, qpvar, dpvar, etc. aliases explicitly since they
279    # are defined in this module and used frequently.
280    # pvar is an alias for print_var.
281    aliases.add(re.sub("print_var", "pvar", called_func_name))
282
283    func_regex = ".*(" + '|'.join(aliases) + ")[ ]*\("
284
285    # Search backward through source lines looking for the calling function
286    # name.
287    found = False
288    for start_line_ix in range(line_ix, 0, -1):
289        # Skip comment lines.
290        if re.match(r"[ ]*#", source_lines[start_line_ix]):
291            continue
292        if re.match(func_regex, source_lines[start_line_ix]):
293            found = True
294            break
295    if not found:
296        print_error("Programmer error - Could not find the source line with" +
297                    " a reference to function \"" + called_func_name + "\".\n")
298        return
299
300    # Search forward through the source lines looking for a line with the
301    # same indentation as the start time.  The end of our composite line
302    # should be the line preceding that line.
303    start_indent = len(source_lines[start_line_ix]) -\
304        len(source_lines[start_line_ix].lstrip(' '))
305    end_line_ix = line_ix
306    for end_line_ix in range(line_ix + 1, len(source_lines)):
307        if source_lines[end_line_ix].strip() == "":
308            continue
309        line_indent = len(source_lines[end_line_ix]) -\
310            len(source_lines[end_line_ix].lstrip(' '))
311        if line_indent == start_indent:
312            end_line_ix -= 1
313            break
314
315    # Join the start line through the end line into a composite line.
316    composite_line = ''.join(map(str.strip,
317                             source_lines[start_line_ix:end_line_ix + 1]))
318
319    # arg_list_etc = re.sub(".*" + called_func_name, "", composite_line)
320    arg_list_etc = "(" + re.sub(func_regex, "", composite_line)
321    if local_debug:
322        print_varx("aliases", aliases, 0, debug_indent)
323        print_varx("func_regex", func_regex, 0, debug_indent)
324        print_varx("start_line_ix", start_line_ix, 0, debug_indent)
325        print_varx("end_line_ix", end_line_ix, 0, debug_indent)
326        print_varx("composite_line", composite_line, 0, debug_indent)
327        print_varx("arg_list_etc", arg_list_etc, 0, debug_indent)
328
329    # Parse arg list...
330    # Initialize...
331    nest_level = -1
332    arg_ix = 0
333    args_list = [""]
334    for ix in range(0, len(arg_list_etc)):
335        char = arg_list_etc[ix]
336        # Set the nest_level based on whether we've encounted a parenthesis.
337        if char == "(":
338            nest_level += 1
339            if nest_level == 0:
340                continue
341        elif char == ")":
342            nest_level -= 1
343            if nest_level < 0:
344                break
345
346        # If we reach a comma at base nest level, we are done processing an
347        # argument so we increment arg_ix and initialize a new args_list entry.
348        if char == "," and nest_level == 0:
349            arg_ix += 1
350            args_list.append("")
351            continue
352
353        # For any other character, we append it it to the current arg list
354        # entry.
355        args_list[arg_ix] += char
356
357    # Trim whitespace from each list entry.
358    args_list = [arg.strip() for arg in args_list]
359
360    if arg_num > len(args_list):
361        print_error("Programmer error - The caller has asked for the name of" +
362                    " argument number \"" + str(arg_num) + "\" but there " +
363                    "were only \"" + str(len(args_list)) + "\" args used:\n" +
364                    sprint_varx("args_list", args_list))
365        return
366
367    argument = args_list[arg_num - 1]
368
369    if local_debug:
370        print_varx("args_list", args_list, 0, debug_indent)
371        print_varx("argument", argument, 0, debug_indent)
372        print_dashes(0, 120)
373
374    return argument
375
376###############################################################################
377
378
379###############################################################################
380def sprint_time(buffer=""):
381
382    r"""
383    Return the time in the following format.
384
385    Example:
386
387    The following python code...
388
389    sys.stdout.write(sprint_time())
390    sys.stdout.write("Hi.\n")
391
392    Will result in the following type of output:
393
394    #(CDT) 2016/07/08 15:25:35 - Hi.
395
396    Example:
397
398    The following python code...
399
400    sys.stdout.write(sprint_time("Hi.\n"))
401
402    Will result in the following type of output:
403
404    #(CDT) 2016/08/03 17:12:05 - Hi.
405
406    The following environment variables will affect the formatting as
407    described:
408    NANOSECONDS                     This will cause the time stamps to be
409                                    precise to the microsecond (Yes, it
410                                    probably should have been named
411                                    MICROSECONDS but the convention was set
412                                    long ago so we're sticking with it).
413                                    Example of the output when environment
414                                    variable NANOSECONDS=1.
415
416    #(CDT) 2016/08/03 17:16:25.510469 - Hi.
417
418    SHOW_ELAPSED_TIME               This will cause the elapsed time to be
419                                    included in the output.  This is the
420                                    amount of time that has elapsed since the
421                                    last time this function was called.  The
422                                    precision of the elapsed time field is
423                                    also affected by the value of the
424                                    NANOSECONDS environment variable.  Example
425                                    of the output when environment variable
426                                    NANOSECONDS=0 and SHOW_ELAPSED_TIME=1.
427
428    #(CDT) 2016/08/03 17:17:40 -    0 - Hi.
429
430    Example of the output when environment variable NANOSECONDS=1 and
431    SHOW_ELAPSED_TIME=1.
432
433    #(CDT) 2016/08/03 17:18:47.317339 -    0.000046 - Hi.
434
435    Description of arguments.
436    buffer                          This will be appended to the formatted
437                                    time string.
438    """
439
440    global NANOSECONDS
441    global SHOW_ELAPSED_TIME
442    global sprint_time_last_seconds
443
444    seconds = time.time()
445    loc_time = time.localtime(seconds)
446    nanoseconds = "%0.6f" % seconds
447    pos = nanoseconds.find(".")
448    nanoseconds = nanoseconds[pos:]
449
450    time_string = time.strftime("#(%Z) %Y/%m/%d %H:%M:%S", loc_time)
451    if NANOSECONDS == "1":
452        time_string = time_string + nanoseconds
453
454    if SHOW_ELAPSED_TIME == "1":
455        cur_time_seconds = seconds
456        math_string = "%9.9f" % cur_time_seconds + " - " + "%9.9f" % \
457            sprint_time_last_seconds
458        elapsed_seconds = eval(math_string)
459        if NANOSECONDS == "1":
460            elapsed_seconds = "%11.6f" % elapsed_seconds
461        else:
462            elapsed_seconds = "%4i" % elapsed_seconds
463        sprint_time_last_seconds = cur_time_seconds
464        time_string = time_string + " - " + elapsed_seconds
465
466    return time_string + " - " + buffer
467
468###############################################################################
469
470
471###############################################################################
472def sprint_timen(buffer=""):
473
474    r"""
475    Append a line feed to the buffer, pass it to sprint_time and return the
476    result.
477    """
478
479    return sprint_time(buffer + "\n")
480
481###############################################################################
482
483
484###############################################################################
485def sprint_error(buffer=""):
486
487    r"""
488    Return a standardized error string.  This includes:
489      - A time stamp
490      - The "**ERROR**" string
491      - The caller's buffer string.
492
493    Example:
494
495    The following python code...
496
497    print(sprint_error("Oops.\n"))
498
499    Will result in the following type of output:
500
501    #(CDT) 2016/08/03 17:12:05 - **ERROR** Oops.
502
503    Description of arguments.
504    buffer                          This will be appended to the formatted
505                                    error string.
506    """
507
508    return sprint_time() + "**ERROR** " + buffer
509
510###############################################################################
511
512
513###############################################################################
514def sprint_varx(var_name,
515                var_value,
516                hex=0,
517                loc_col1_indent=col1_indent,
518                loc_col1_width=col1_width,
519                trailing_char="\n"):
520
521    r"""
522    Print the var name/value passed to it.  If the caller lets loc_col1_width
523    default, the printing lines up nicely with output generated by the
524    print_time functions.
525
526    Note that the sprint_var function (defined below) can be used to call this
527    function so that the programmer does not need to pass the var_name.
528    sprint_var will figure out the var_name.  The sprint_var function is the
529    one that would normally be used by the general user.
530
531    For example, the following python code:
532
533    first_name = "Mike"
534    print_time("Doing this...\n")
535    print_varx("first_name", first_name)
536    print_time("Doing that...\n")
537
538    Will generate output like this:
539
540    #(CDT) 2016/08/10 17:34:42.847374 -    0.001285 - Doing this...
541    first_name:                                       Mike
542    #(CDT) 2016/08/10 17:34:42.847510 -    0.000136 - Doing that...
543
544    This function recognizes several complex types of data such as dict, list
545    or tuple.
546
547    For example, the following python code:
548
549    my_dict = dict(one=1, two=2, three=3)
550    print_var(my_dict)
551
552    Will generate the following output:
553
554    my_dict:
555      my_dict[three]:                                 3
556      my_dict[two]:                                   2
557      my_dict[one]:                                   1
558
559    Description of arguments.
560    var_name                        The name of the variable to be printed.
561    var_value                       The value of the variable to be printed.
562    hex                             This indicates that the value should be
563                                    printed in hex format.  It is the user's
564                                    responsibility to ensure that a var_value
565                                    contains a valid hex number.  For string
566                                    var_values, this will be interpreted as
567                                    show_blanks which means that blank values
568                                    will be printed as "<blank>".
569    loc_col1_indent                 The number of spaces to indent the output.
570    loc_col1_width                  The width of the output column containing
571                                    the variable name.  The default value of
572                                    this is adjusted so that the var_value
573                                    lines up with text printed via the
574                                    print_time function.
575    trailing_char                   The character to be used at the end of the
576                                    returned string.  The default value is a
577                                    line feed.
578    """
579
580    # Determine the type
581    if type(var_value) in (int, float, bool, str, unicode) \
582       or var_value is None:
583        # The data type is simple in the sense that it has no subordinate
584        # parts.
585        # Adjust loc_col1_width.
586        loc_col1_width = loc_col1_width - loc_col1_indent
587        # See if the user wants the output in hex format.
588        if hex:
589            if type(var_value) not in (int, long):
590                value_format = "%s"
591                if var_value == "":
592                    var_value = "<blank>"
593            else:
594                value_format = "0x%08x"
595        else:
596            value_format = "%s"
597        format_string = "%" + str(loc_col1_indent) + "s%-" \
598            + str(loc_col1_width) + "s" + value_format + trailing_char
599        return format_string % ("", var_name + ":", var_value)
600    else:
601        # The data type is complex in the sense that it has subordinate parts.
602        format_string = "%" + str(loc_col1_indent) + "s%s\n"
603        buffer = format_string % ("", var_name + ":")
604        loc_col1_indent += 2
605        try:
606            length = len(var_value)
607        except TypeError:
608            length = 0
609        ix = 0
610        loc_trailing_char = "\n"
611        type_is_dict = 0
612        if type(var_value) is dict:
613            type_is_dict = 1
614        if not type_is_dict:
615            try:
616                if type(var_value) is collections.OrderedDict:
617                    type_is_dict = 1
618            except AttributeError:
619                pass
620        if not type_is_dict:
621            try:
622                if type(var_value) is DotDict:
623                    type_is_dict = 1
624            except NameError:
625                pass
626        if type_is_dict:
627            for key, value in var_value.iteritems():
628                ix += 1
629                if ix == length:
630                    loc_trailing_char = trailing_char
631                buffer += sprint_varx(var_name + "[" + key + "]", value, hex,
632                                      loc_col1_indent, loc_col1_width,
633                                      loc_trailing_char)
634        elif type(var_value) in (list, tuple, set):
635            for key, value in enumerate(var_value):
636                ix += 1
637                if ix == length:
638                    loc_trailing_char = trailing_char
639                buffer += sprint_varx(var_name + "[" + str(key) + "]", value,
640                                      hex, loc_col1_indent, loc_col1_width,
641                                      loc_trailing_char)
642        elif type(var_value) is argparse.Namespace:
643            for key in var_value.__dict__:
644                ix += 1
645                if ix == length:
646                    loc_trailing_char = trailing_char
647                cmd_buf = "buffer += sprint_varx(var_name + \".\" + str(key)" \
648                          + ", var_value." + key + ", hex, loc_col1_indent," \
649                          + " loc_col1_width, loc_trailing_char)"
650                exec(cmd_buf)
651        else:
652            var_type = type(var_value).__name__
653            func_name = sys._getframe().f_code.co_name
654            var_value = "<" + var_type + " type not supported by " + \
655                        func_name + "()>"
656            value_format = "%s"
657            loc_col1_indent -= 2
658            # Adjust loc_col1_width.
659            loc_col1_width = loc_col1_width - loc_col1_indent
660            format_string = "%" + str(loc_col1_indent) + "s%-" \
661                + str(loc_col1_width) + "s" + value_format + trailing_char
662            return format_string % ("", var_name + ":", var_value)
663
664        return buffer
665
666    return ""
667
668###############################################################################
669
670
671###############################################################################
672def sprint_var(*args):
673
674    r"""
675    Figure out the name of the first argument for you and then call
676    sprint_varx with it.  Therefore, the following 2 calls are equivalent:
677    sprint_varx("var1", var1)
678    sprint_var(var1)
679    """
680
681    # Get the name of the first variable passed to this function.
682    stack_frame = 2
683    caller_func_name = sprint_func_name(2)
684    if caller_func_name.endswith("print_var"):
685        stack_frame += 1
686    var_name = get_arg_name(None, 1, stack_frame)
687    return sprint_varx(var_name, *args)
688
689###############################################################################
690
691
692###############################################################################
693def sprint_vars(*args):
694
695    r"""
696    Sprint the values of one or more variables.
697
698    Description of args:
699    args:
700        If the first argument is an integer, it will be interpreted to be the
701        "indent" value.
702        If the second argument is an integer, it will be interpreted to be the
703        "col1_width" value.
704        If the third argument is an integer, it will be interpreted to be the
705        "hex" value.
706        All remaining parms are considered variable names which are to be
707        sprinted.
708    """
709
710    if len(args) == 0:
711        return
712
713    # Get the name of the first variable passed to this function.
714    stack_frame = 2
715    caller_func_name = sprint_func_name(2)
716    if caller_func_name.endswith("print_vars"):
717        stack_frame += 1
718
719    parm_num = 1
720
721    # Create list from args (which is a tuple) so that it can be modified.
722    args_list = list(args)
723
724    var_name = get_arg_name(None, parm_num, stack_frame)
725    # See if parm 1 is to be interpreted as "indent".
726    try:
727        if type(int(var_name)) is int:
728            indent = int(var_name)
729            args_list.pop(0)
730            parm_num += 1
731    except ValueError:
732        indent = 0
733
734    var_name = get_arg_name(None, parm_num, stack_frame)
735    # See if parm 1 is to be interpreted as "col1_width".
736    try:
737        if type(int(var_name)) is int:
738            loc_col1_width = int(var_name)
739            args_list.pop(0)
740            parm_num += 1
741    except ValueError:
742        loc_col1_width = col1_width
743
744    var_name = get_arg_name(None, parm_num, stack_frame)
745    # See if parm 1 is to be interpreted as "hex".
746    try:
747        if type(int(var_name)) is int:
748            hex = int(var_name)
749            args_list.pop(0)
750            parm_num += 1
751    except ValueError:
752        hex = 0
753
754    buffer = ""
755    for var_value in args_list:
756        var_name = get_arg_name(None, parm_num, stack_frame)
757        buffer += sprint_varx(var_name, var_value, hex, indent, loc_col1_width)
758        parm_num += 1
759
760    return buffer
761
762###############################################################################
763
764
765###############################################################################
766def lprint_varx(var_name,
767                var_value,
768                hex=0,
769                loc_col1_indent=col1_indent,
770                loc_col1_width=col1_width,
771                log_level=getattr(logging, 'INFO')):
772
773    r"""
774    Send sprint_varx output to logging.
775    """
776
777    logging.log(log_level, sprint_varx(var_name, var_value, hex,
778                loc_col1_indent, loc_col1_width, ""))
779
780###############################################################################
781
782
783###############################################################################
784def lprint_var(*args):
785
786    r"""
787    Figure out the name of the first argument for you and then call
788    lprint_varx with it.  Therefore, the following 2 calls are equivalent:
789    lprint_varx("var1", var1)
790    lprint_var(var1)
791    """
792
793    # Get the name of the first variable passed to this function.
794    stack_frame = 2
795    caller_func_name = sprint_func_name(2)
796    if caller_func_name.endswith("print_var"):
797        stack_frame += 1
798    var_name = get_arg_name(None, 1, stack_frame)
799    lprint_varx(var_name, *args)
800
801###############################################################################
802
803
804###############################################################################
805def sprint_dashes(indent=col1_indent,
806                  width=80,
807                  line_feed=1,
808                  char="-"):
809
810    r"""
811    Return a string of dashes to the caller.
812
813    Description of arguements:
814    indent                          The number of characters to indent the
815                                    output.
816    width                           The width of the string of dashes.
817    line_feed                       Indicates whether the output should end
818                                    with a line feed.
819    char                            The character to be repeated in the output
820                                    string.
821    """
822
823    width = int(width)
824    buffer = " " * int(indent) + char * width
825    if line_feed:
826        buffer += "\n"
827
828    return buffer
829
830###############################################################################
831
832
833###############################################################################
834def sindent(text="",
835            indent=0):
836
837    r"""
838    Pre-pend the specified number of characters to the text string (i.e.
839    indent it) and return it.
840
841    Description of arguments:
842    text                            The string to be indented.
843    indent                          The number of characters to indent the
844                                    string.
845    """
846
847    format_string = "%" + str(indent) + "s%s"
848    buffer = format_string % ("", text)
849
850    return buffer
851
852###############################################################################
853
854
855###############################################################################
856def sprint_call_stack(indent=0,
857                      stack_frame_ix=0):
858
859    r"""
860    Return a call stack report for the given point in the program with line
861    numbers, function names and function parameters and arguments.
862
863    Sample output:
864
865    -------------------------------------------------------------------------
866    Python function call stack
867
868    Line # Function name and arguments
869    ------ ------------------------------------------------------------------
870       424 sprint_call_stack ()
871         4 print_call_stack ()
872        31 func1 (last_name = 'walsh', first_name = 'mikey')
873        59 /tmp/scr5.py
874    -------------------------------------------------------------------------
875
876    Description of arguments:
877    indent                          The number of characters to indent each
878                                    line of output.
879    stack_frame_ix                  The index of the first stack frame which
880                                    is to be returned.
881    """
882
883    buffer = ""
884    buffer += sprint_dashes(indent)
885    buffer += sindent("Python function call stack\n\n", indent)
886    buffer += sindent("Line # Function name and arguments\n", indent)
887    buffer += sprint_dashes(indent, 6, 0) + " " + sprint_dashes(0, 73)
888
889    # Grab the current program stack.
890    current_stack = inspect.stack()
891
892    # Process each frame in turn.
893    format_string = "%6s %s\n"
894    ix = 0
895    for stack_frame in current_stack:
896        if ix < stack_frame_ix:
897            ix += 1
898            continue
899        # I want the line number shown to be the line where you find the line
900        # shown.
901        try:
902            line_num = str(current_stack[ix + 1][2])
903        except IndexError:
904            line_num = ""
905        func_name = str(stack_frame[3])
906        if func_name == "?":
907            # "?" is the name used when code is not in a function.
908            func_name = "(none)"
909
910        if func_name == "<module>":
911            # If the func_name is the "main" program, we simply get the
912            # command line call string.
913            func_and_args = ' '.join(sys.argv)
914        else:
915            # Get the program arguments.
916            arg_vals = inspect.getargvalues(stack_frame[0])
917            function_parms = arg_vals[0]
918            frame_locals = arg_vals[3]
919
920            args_list = []
921            for arg_name in function_parms:
922                # Get the arg value from frame locals.
923                arg_value = frame_locals[arg_name]
924                args_list.append(arg_name + " = " + repr(arg_value))
925            args_str = "(" + ', '.join(map(str, args_list)) + ")"
926
927            # Now we need to print this in a nicely-wrapped way.
928            func_and_args = func_name + " " + args_str
929
930        buffer += sindent(format_string % (line_num, func_and_args), indent)
931        ix += 1
932
933    buffer += sprint_dashes(indent)
934
935    return buffer
936
937###############################################################################
938
939
940###############################################################################
941def sprint_executing(stack_frame_ix=None):
942
943    r"""
944    Print a line indicating what function is executing and with what parameter
945    values.  This is useful for debugging.
946
947    Sample output:
948
949    #(CDT) 2016/08/25 17:54:27 - Executing: func1 (x = 1)
950
951    Description of arguments:
952    stack_frame_ix                  The index of the stack frame whose
953                                    function info should be returned.  If the
954                                    caller does not specifiy a value, this
955                                    function will set the value to 1 which is
956                                    the index of the caller's stack frame.  If
957                                    the caller is the wrapper function
958                                    "print_executing", this function will bump
959                                    it up by 1.
960    """
961
962    # If user wants default stack_frame_ix.
963    if stack_frame_ix is None:
964        func_name = sys._getframe().f_code.co_name
965        caller_func_name = sys._getframe(1).f_code.co_name
966        if caller_func_name.endswith(func_name[1:]):
967            stack_frame_ix = 2
968        else:
969            stack_frame_ix = 1
970
971    stack_frame = inspect.stack()[stack_frame_ix]
972
973    func_name = str(stack_frame[3])
974    if func_name == "?":
975        # "?" is the name used when code is not in a function.
976        func_name = "(none)"
977
978    if func_name == "<module>":
979        # If the func_name is the "main" program, we simply get the command
980        # line call string.
981        func_and_args = ' '.join(sys.argv)
982    else:
983        # Get the program arguments.
984        arg_vals = inspect.getargvalues(stack_frame[0])
985        function_parms = arg_vals[0]
986        frame_locals = arg_vals[3]
987
988        args_list = []
989        for arg_name in function_parms:
990            # Get the arg value from frame locals.
991            arg_value = frame_locals[arg_name]
992            args_list.append(arg_name + " = " + repr(arg_value))
993        args_str = "(" + ', '.join(map(str, args_list)) + ")"
994
995        # Now we need to print this in a nicely-wrapped way.
996        func_and_args = func_name + " " + args_str
997
998    return sprint_time() + "Executing: " + func_and_args + "\n"
999
1000###############################################################################
1001
1002
1003###############################################################################
1004def sprint_pgm_header(indent=0,
1005                      linefeed=1):
1006
1007    r"""
1008    Return a standardized header that programs should print at the beginning
1009    of the run.  It includes useful information like command line, pid,
1010    userid, program parameters, etc.
1011
1012    Description of arguments:
1013    indent                          The number of characters to indent each
1014                                    line of output.
1015    linefeed                        Indicates whether a line feed be included
1016                                    at the beginning and end of the report.
1017    """
1018
1019    loc_col1_width = col1_width + indent
1020
1021    buffer = ""
1022    if linefeed:
1023        buffer = "\n"
1024
1025    buffer += sindent(sprint_time() + "Running " + pgm_name + ".\n", indent)
1026    buffer += sindent(sprint_time() + "Program parameter values, etc.:\n\n",
1027                      indent)
1028    buffer += sprint_varx("command_line", ' '.join(sys.argv), 0, indent,
1029                          loc_col1_width)
1030    # We want the output to show a customized name for the pid and pgid but
1031    # we want it to look like a valid variable name.  Therefore, we'll use
1032    # pgm_name_var_name which was set when this module was imported.
1033    buffer += sprint_varx(pgm_name_var_name + "_pid", os.getpid(), 0, indent,
1034                          loc_col1_width)
1035    buffer += sprint_varx(pgm_name_var_name + "_pgid", os.getpgrp(), 0, indent,
1036                          loc_col1_width)
1037    userid_num = str(os.geteuid())
1038    try:
1039        username = os.getlogin()
1040    except OSError:
1041        if userid_num == "0":
1042            username = "root"
1043        else:
1044            username = "?"
1045    buffer += sprint_varx("uid", userid_num + " (" + username +
1046                          ")", 0, indent, loc_col1_width)
1047    buffer += sprint_varx("gid", str(os.getgid()) + " (" +
1048                          str(grp.getgrgid(os.getgid()).gr_name) + ")", 0,
1049                          indent, loc_col1_width)
1050    buffer += sprint_varx("host_name", socket.gethostname(), 0, indent,
1051                          loc_col1_width)
1052    try:
1053        DISPLAY = os.environ['DISPLAY']
1054    except KeyError:
1055        DISPLAY = ""
1056    buffer += sprint_varx("DISPLAY", DISPLAY, 0, indent,
1057                          loc_col1_width)
1058    # I want to add code to print caller's parms.
1059
1060    # __builtin__.arg_obj is created by the get_arg module function,
1061    # gen_get_options.
1062    try:
1063        buffer += ga.sprint_args(__builtin__.arg_obj, indent)
1064    except AttributeError:
1065        pass
1066
1067    if linefeed:
1068        buffer += "\n"
1069
1070    return buffer
1071
1072###############################################################################
1073
1074
1075###############################################################################
1076def sprint_error_report(error_text="\n",
1077                        indent=2):
1078
1079    r"""
1080    Return a string with a standardized report which includes the caller's
1081    error text, the call stack and the program header.
1082
1083    Description of args:
1084    error_text                      The error text to be included in the
1085                                    report.  The caller should include any
1086                                    needed linefeeds.
1087    indent                          The number of characters to indent each
1088                                    line of output.
1089    """
1090
1091    buffer = ""
1092    buffer += sprint_dashes(width=120, char="=")
1093    buffer += sprint_error(error_text)
1094    buffer += "\n"
1095    # Calling sprint_call_stack with stack_frame_ix of 0 causes it to show
1096    # itself and this function in the call stack.  This is not helpful to a
1097    # debugger and is therefore clutter.  We will adjust the stack_frame_ix to
1098    # hide that information.
1099    stack_frame_ix = 2
1100    caller_func_name = sprint_func_name(2)
1101    if caller_func_name.endswith("print_error_report"):
1102        stack_frame_ix += 1
1103    buffer += sprint_call_stack(indent, stack_frame_ix)
1104    buffer += sprint_pgm_header(indent)
1105    buffer += sprint_dashes(width=120, char="=")
1106
1107    return buffer
1108
1109###############################################################################
1110
1111
1112###############################################################################
1113def sprint_issuing(cmd_buf,
1114                   test_mode=0):
1115
1116    r"""
1117    Return a line indicating a command that the program is about to execute.
1118
1119    Sample output for a cmd_buf of "ls"
1120
1121    #(CDT) 2016/08/25 17:57:36 - Issuing: ls
1122
1123    Description of args:
1124    cmd_buf                         The command to be executed by caller.
1125    test_mode                       With test_mode set, your output will look
1126                                    like this:
1127
1128    #(CDT) 2016/08/25 17:57:36 - (test_mode) Issuing: ls
1129
1130    """
1131
1132    buffer = sprint_time()
1133    if test_mode:
1134        buffer += "(test_mode) "
1135    buffer += "Issuing: " + cmd_buf + "\n"
1136
1137    return buffer
1138
1139###############################################################################
1140
1141
1142###############################################################################
1143def sprint_pgm_footer():
1144
1145    r"""
1146    Return a standardized footer that programs should print at the end of the
1147    program run.  It includes useful information like total run time, etc.
1148    """
1149
1150    buffer = "\n" + sprint_time() + "Finished running " + pgm_name + ".\n\n"
1151
1152    total_time = time.time() - start_time
1153    total_time_string = "%0.6f" % total_time
1154
1155    buffer += sprint_varx(pgm_name_var_name + "_runtime", total_time_string)
1156    buffer += "\n"
1157
1158    return buffer
1159
1160###############################################################################
1161
1162
1163###############################################################################
1164def sprint(buffer=""):
1165
1166    r"""
1167    Simply return the user's buffer.  This function is used by the qprint and
1168    dprint functions defined dynamically below, i.e. it would not normally be
1169    called for general use.
1170
1171    Description of arguments.
1172    buffer                          This will be returned to the caller.
1173    """
1174
1175    return str(buffer)
1176
1177###############################################################################
1178
1179
1180###############################################################################
1181def sprintn(buffer=""):
1182
1183    r"""
1184    Simply return the user's buffer with a line feed.  This function is used
1185    by the qprint and dprint functions defined dynamically below, i.e. it
1186    would not normally be called for general use.
1187
1188    Description of arguments.
1189    buffer                          This will be returned to the caller.
1190    """
1191
1192    buffer = str(buffer) + "\n"
1193
1194    return buffer
1195
1196###############################################################################
1197
1198
1199###############################################################################
1200# In the following section of code, we will dynamically create print versions
1201# for each of the sprint functions defined above.  So, for example, where we
1202# have an sprint_time() function defined above that returns the time to the
1203# caller in a string, we will create a corresponding print_time() function
1204# that will print that string directly to stdout.
1205
1206# It can be complicated to follow what's being creaed by the exec statement
1207# below.  Here is an example of the print_time() function that will be created:
1208
1209# def print_time(*args):
1210#   s_funcname = "s" + sys._getframe().f_code.co_name
1211#   s_func = getattr(sys.modules[__name__], s_funcname)
1212#   sys.stdout.write(s_func(*args))
1213
1214# Here are comments describing the 3 lines in the body of the created function.
1215# Calculate the "s" version of this function name (e.g. if this function name
1216# is print_time, we want s_funcname to be "sprint_time".
1217# Put a reference to the "s" version of this function in s_func.
1218# Call the "s" version of this function passing it all of our arguments.
1219# Write the result to stdout.
1220
1221# func_names contains a list of all print functions which should be created
1222# from their sprint counterparts.
1223func_names = ['print_time', 'print_timen', 'print_error', 'print_varx',
1224              'print_var', 'print_vars', 'print_dashes', 'indent',
1225              'print_call_stack', 'print_func_name', 'print_executing',
1226              'print_pgm_header', 'print_issuing', 'print_pgm_footer',
1227              'print_error_report', 'print', 'printn']
1228
1229for func_name in func_names:
1230    if func_name == "print":
1231        continue
1232    # Create abbreviated aliases (e.g. spvar is an alias for sprint_var).
1233    alias = re.sub("print_", "p", func_name)
1234    pgm_definition_string = "s" + alias + " = s" + func_name
1235    if gen_print_debug:
1236        print(pgm_definition_string)
1237    exec(pgm_definition_string)
1238
1239for func_name in func_names:
1240    if func_name == "print_error" or func_name == "print_error_report":
1241        output_stream = "stderr"
1242    else:
1243        output_stream = "stdout"
1244    func_def = \
1245        [
1246            "def " + func_name + "(*args):",
1247            "  s_func_name = \"s\" + sys._getframe().f_code.co_name",
1248            "  s_func = getattr(sys.modules[__name__], s_func_name)",
1249            "  sys." + output_stream + ".write(s_func(*args))",
1250            "  sys." + output_stream + ".flush()"
1251        ]
1252    if func_name != "print":
1253        pgm_definition_string = '\n'.join(func_def)
1254        if gen_print_debug:
1255            print(pgm_definition_string)
1256        exec(pgm_definition_string)
1257
1258    # Now define "q" versions of each print function.
1259    func_def = \
1260        [
1261            "def q" + func_name + "(*args):",
1262            "  if __builtin__.quiet: return",
1263            "  s_func_name = \"s" + func_name + "\"",
1264            "  s_func = getattr(sys.modules[__name__], s_func_name)",
1265            "  sys." + output_stream + ".write(s_func(*args))",
1266            "  sys." + output_stream + ".flush()"
1267        ]
1268
1269    pgm_definition_string = '\n'.join(func_def)
1270    if gen_print_debug:
1271        print(pgm_definition_string)
1272    exec(pgm_definition_string)
1273
1274    # Now define "d" versions of each print function.
1275    func_def = \
1276        [
1277            "def d" + func_name + "(*args):",
1278            "  if not __builtin__.debug: return",
1279            "  s_func_name = \"s" + func_name + "\"",
1280            "  s_func = getattr(sys.modules[__name__], s_func_name)",
1281            "  sys." + output_stream + ".write(s_func(*args))",
1282            "  sys." + output_stream + ".flush()"
1283        ]
1284
1285    pgm_definition_string = '\n'.join(func_def)
1286    if gen_print_debug:
1287        print(pgm_definition_string)
1288    exec(pgm_definition_string)
1289
1290    # Now define "l" versions of each print function.
1291    func_def = \
1292        [
1293            "def l" + func_name + "(*args):",
1294            "  s_func_name = \"s" + func_name + "\"",
1295            "  s_func = getattr(sys.modules[__name__], s_func_name)",
1296            "  logging.log(getattr(logging, 'INFO'), s_func(*args))",
1297        ]
1298
1299    if func_name != "print_varx" and func_name != "print_var":
1300        pgm_definition_string = '\n'.join(func_def)
1301        if gen_print_debug:
1302            print(pgm_definition_string)
1303        exec(pgm_definition_string)
1304
1305    if func_name == "print":
1306        continue
1307
1308    # Create abbreviated aliases (e.g. pvar is an alias for print_var).
1309    alias = re.sub("print_", "p", func_name)
1310    pgm_definition_string = alias + " = " + func_name
1311    if gen_print_debug:
1312        print(pgm_definition_string)
1313    exec(pgm_definition_string)
1314
1315    # Create abbreviated aliases (e.g. qpvar is an alias for qprint_var).
1316    alias = re.sub("print_", "p", func_name)
1317    pgm_definition_string = "q" + alias + " = q" + func_name
1318    if gen_print_debug:
1319        print(pgm_definition_string)
1320    exec(pgm_definition_string)
1321
1322    # Create abbreviated aliases (e.g. dpvar is an alias for dprint_var).
1323    alias = re.sub("print_", "p", func_name)
1324    pgm_definition_string = "d" + alias + " = d" + func_name
1325    if gen_print_debug:
1326        print(pgm_definition_string)
1327    exec(pgm_definition_string)
1328
1329    # Create abbreviated aliases (e.g. lpvar is an alias for lprint_var).
1330    alias = re.sub("print_", "p", func_name)
1331    pgm_definition_string = "l" + alias + " = l" + func_name
1332    if gen_print_debug:
1333        print(pgm_definition_string)
1334    exec(pgm_definition_string)
1335
1336###############################################################################
1337