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