xref: /openbmc/openbmc-test-automation/lib/gen_print.py (revision 80dd5af3f5f09252592b69daebae9b5cd65bb1fd)
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>".  For dict
570                                    var_values, this will be interpreted as
571                                    terse format where keys are not repeated
572                                    in the output.
573    loc_col1_indent                 The number of spaces to indent the output.
574    loc_col1_width                  The width of the output column containing
575                                    the variable name.  The default value of
576                                    this is adjusted so that the var_value
577                                    lines up with text printed via the
578                                    print_time function.
579    trailing_char                   The character to be used at the end of the
580                                    returned string.  The default value is a
581                                    line feed.
582    """
583
584    # Determine the type
585    if type(var_value) in (int, float, bool, str, unicode) \
586       or var_value is None:
587        # The data type is simple in the sense that it has no subordinate
588        # parts.
589        # Adjust loc_col1_width.
590        loc_col1_width = loc_col1_width - loc_col1_indent
591        # See if the user wants the output in hex format.
592        if hex:
593            if type(var_value) not in (int, long):
594                value_format = "%s"
595                if var_value == "":
596                    var_value = "<blank>"
597            else:
598                value_format = "0x%08x"
599        else:
600            value_format = "%s"
601        format_string = "%" + str(loc_col1_indent) + "s%-" \
602            + str(loc_col1_width) + "s" + value_format + trailing_char
603        return format_string % ("", var_name + ":", var_value)
604    else:
605        # The data type is complex in the sense that it has subordinate parts.
606        format_string = "%" + str(loc_col1_indent) + "s%s\n"
607        buffer = format_string % ("", var_name + ":")
608        loc_col1_indent += 2
609        try:
610            length = len(var_value)
611        except TypeError:
612            length = 0
613        ix = 0
614        loc_trailing_char = "\n"
615        type_is_dict = 0
616        if type(var_value) is dict:
617            type_is_dict = 1
618        try:
619            if type(var_value) is collections.OrderedDict:
620                type_is_dict = 1
621        except AttributeError:
622            pass
623        try:
624            if type(var_value) is DotDict:
625                type_is_dict = 1
626        except NameError:
627            pass
628        try:
629            if type(var_value) is NormalizedDict:
630                type_is_dict = 1
631        except NameError:
632            pass
633        if type_is_dict:
634            for key, value in var_value.iteritems():
635                ix += 1
636                if ix == length:
637                    loc_trailing_char = trailing_char
638                if hex:
639                    buffer += sprint_varx(key, value,
640                                          hex, loc_col1_indent, loc_col1_width,
641                                          loc_trailing_char)
642                else:
643                    buffer += sprint_varx(var_name + "[" + key + "]", value,
644                                          hex, loc_col1_indent, loc_col1_width,
645                                          loc_trailing_char)
646        elif type(var_value) in (list, tuple, set):
647            for key, value in enumerate(var_value):
648                ix += 1
649                if ix == length:
650                    loc_trailing_char = trailing_char
651                buffer += sprint_varx(var_name + "[" + str(key) + "]", value,
652                                      hex, loc_col1_indent, loc_col1_width,
653                                      loc_trailing_char)
654        elif type(var_value) is argparse.Namespace:
655            for key in var_value.__dict__:
656                ix += 1
657                if ix == length:
658                    loc_trailing_char = trailing_char
659                cmd_buf = "buffer += sprint_varx(var_name + \".\" + str(key)" \
660                          + ", var_value." + key + ", hex, loc_col1_indent," \
661                          + " loc_col1_width, loc_trailing_char)"
662                exec(cmd_buf)
663        else:
664            var_type = type(var_value).__name__
665            func_name = sys._getframe().f_code.co_name
666            var_value = "<" + var_type + " type not supported by " + \
667                        func_name + "()>"
668            value_format = "%s"
669            loc_col1_indent -= 2
670            # Adjust loc_col1_width.
671            loc_col1_width = loc_col1_width - loc_col1_indent
672            format_string = "%" + str(loc_col1_indent) + "s%-" \
673                + str(loc_col1_width) + "s" + value_format + trailing_char
674            return format_string % ("", var_name + ":", var_value)
675
676        return buffer
677
678    return ""
679
680###############################################################################
681
682
683###############################################################################
684def sprint_var(*args):
685
686    r"""
687    Figure out the name of the first argument for you and then call
688    sprint_varx with it.  Therefore, the following 2 calls are equivalent:
689    sprint_varx("var1", var1)
690    sprint_var(var1)
691    """
692
693    # Get the name of the first variable passed to this function.
694    stack_frame = 2
695    caller_func_name = sprint_func_name(2)
696    if caller_func_name.endswith("print_var"):
697        stack_frame += 1
698    var_name = get_arg_name(None, 1, stack_frame)
699    return sprint_varx(var_name, *args)
700
701###############################################################################
702
703
704###############################################################################
705def sprint_vars(*args):
706
707    r"""
708    Sprint the values of one or more variables.
709
710    Description of args:
711    args:
712        If the first argument is an integer, it will be interpreted to be the
713        "indent" value.
714        If the second argument is an integer, it will be interpreted to be the
715        "col1_width" value.
716        If the third argument is an integer, it will be interpreted to be the
717        "hex" value.
718        All remaining parms are considered variable names which are to be
719        sprinted.
720    """
721
722    if len(args) == 0:
723        return
724
725    # Get the name of the first variable passed to this function.
726    stack_frame = 2
727    caller_func_name = sprint_func_name(2)
728    if caller_func_name.endswith("print_vars"):
729        stack_frame += 1
730
731    parm_num = 1
732
733    # Create list from args (which is a tuple) so that it can be modified.
734    args_list = list(args)
735
736    var_name = get_arg_name(None, parm_num, stack_frame)
737    # See if parm 1 is to be interpreted as "indent".
738    try:
739        if type(int(var_name)) is int:
740            indent = int(var_name)
741            args_list.pop(0)
742            parm_num += 1
743    except ValueError:
744        indent = 0
745
746    var_name = get_arg_name(None, parm_num, stack_frame)
747    # See if parm 1 is to be interpreted as "col1_width".
748    try:
749        if type(int(var_name)) is int:
750            loc_col1_width = int(var_name)
751            args_list.pop(0)
752            parm_num += 1
753    except ValueError:
754        loc_col1_width = col1_width
755
756    var_name = get_arg_name(None, parm_num, stack_frame)
757    # See if parm 1 is to be interpreted as "hex".
758    try:
759        if type(int(var_name)) is int:
760            hex = int(var_name)
761            args_list.pop(0)
762            parm_num += 1
763    except ValueError:
764        hex = 0
765
766    buffer = ""
767    for var_value in args_list:
768        var_name = get_arg_name(None, parm_num, stack_frame)
769        buffer += sprint_varx(var_name, var_value, hex, indent, loc_col1_width)
770        parm_num += 1
771
772    return buffer
773
774###############################################################################
775
776
777###############################################################################
778def lprint_varx(var_name,
779                var_value,
780                hex=0,
781                loc_col1_indent=col1_indent,
782                loc_col1_width=col1_width,
783                log_level=getattr(logging, 'INFO')):
784
785    r"""
786    Send sprint_varx output to logging.
787    """
788
789    logging.log(log_level, sprint_varx(var_name, var_value, hex,
790                loc_col1_indent, loc_col1_width, ""))
791
792###############################################################################
793
794
795###############################################################################
796def lprint_var(*args):
797
798    r"""
799    Figure out the name of the first argument for you and then call
800    lprint_varx with it.  Therefore, the following 2 calls are equivalent:
801    lprint_varx("var1", var1)
802    lprint_var(var1)
803    """
804
805    # Get the name of the first variable passed to this function.
806    stack_frame = 2
807    caller_func_name = sprint_func_name(2)
808    if caller_func_name.endswith("print_var"):
809        stack_frame += 1
810    var_name = get_arg_name(None, 1, stack_frame)
811    lprint_varx(var_name, *args)
812
813###############################################################################
814
815
816###############################################################################
817def sprint_dashes(indent=col1_indent,
818                  width=80,
819                  line_feed=1,
820                  char="-"):
821
822    r"""
823    Return a string of dashes to the caller.
824
825    Description of arguements:
826    indent                          The number of characters to indent the
827                                    output.
828    width                           The width of the string of dashes.
829    line_feed                       Indicates whether the output should end
830                                    with a line feed.
831    char                            The character to be repeated in the output
832                                    string.
833    """
834
835    width = int(width)
836    buffer = " " * int(indent) + char * width
837    if line_feed:
838        buffer += "\n"
839
840    return buffer
841
842###############################################################################
843
844
845###############################################################################
846def sindent(text="",
847            indent=0):
848
849    r"""
850    Pre-pend the specified number of characters to the text string (i.e.
851    indent it) and return it.
852
853    Description of arguments:
854    text                            The string to be indented.
855    indent                          The number of characters to indent the
856                                    string.
857    """
858
859    format_string = "%" + str(indent) + "s%s"
860    buffer = format_string % ("", text)
861
862    return buffer
863
864###############################################################################
865
866
867###############################################################################
868def sprint_call_stack(indent=0,
869                      stack_frame_ix=0):
870
871    r"""
872    Return a call stack report for the given point in the program with line
873    numbers, function names and function parameters and arguments.
874
875    Sample output:
876
877    -------------------------------------------------------------------------
878    Python function call stack
879
880    Line # Function name and arguments
881    ------ ------------------------------------------------------------------
882       424 sprint_call_stack ()
883         4 print_call_stack ()
884        31 func1 (last_name = 'walsh', first_name = 'mikey')
885        59 /tmp/scr5.py
886    -------------------------------------------------------------------------
887
888    Description of arguments:
889    indent                          The number of characters to indent each
890                                    line of output.
891    stack_frame_ix                  The index of the first stack frame which
892                                    is to be returned.
893    """
894
895    buffer = ""
896    buffer += sprint_dashes(indent)
897    buffer += sindent("Python function call stack\n\n", indent)
898    buffer += sindent("Line # Function name and arguments\n", indent)
899    buffer += sprint_dashes(indent, 6, 0) + " " + sprint_dashes(0, 73)
900
901    # Grab the current program stack.
902    current_stack = inspect.stack()
903
904    # Process each frame in turn.
905    format_string = "%6s %s\n"
906    ix = 0
907    for stack_frame in current_stack:
908        if ix < stack_frame_ix:
909            ix += 1
910            continue
911        # I want the line number shown to be the line where you find the line
912        # shown.
913        try:
914            line_num = str(current_stack[ix + 1][2])
915        except IndexError:
916            line_num = ""
917        func_name = str(stack_frame[3])
918        if func_name == "?":
919            # "?" is the name used when code is not in a function.
920            func_name = "(none)"
921
922        if func_name == "<module>":
923            # If the func_name is the "main" program, we simply get the
924            # command line call string.
925            func_and_args = ' '.join(sys.argv)
926        else:
927            # Get the program arguments.
928            arg_vals = inspect.getargvalues(stack_frame[0])
929            function_parms = arg_vals[0]
930            frame_locals = arg_vals[3]
931
932            args_list = []
933            for arg_name in function_parms:
934                # Get the arg value from frame locals.
935                arg_value = frame_locals[arg_name]
936                args_list.append(arg_name + " = " + repr(arg_value))
937            args_str = "(" + ', '.join(map(str, args_list)) + ")"
938
939            # Now we need to print this in a nicely-wrapped way.
940            func_and_args = func_name + " " + args_str
941
942        buffer += sindent(format_string % (line_num, func_and_args), indent)
943        ix += 1
944
945    buffer += sprint_dashes(indent)
946
947    return buffer
948
949###############################################################################
950
951
952###############################################################################
953def sprint_executing(stack_frame_ix=None):
954
955    r"""
956    Print a line indicating what function is executing and with what parameter
957    values.  This is useful for debugging.
958
959    Sample output:
960
961    #(CDT) 2016/08/25 17:54:27 - Executing: func1 (x = 1)
962
963    Description of arguments:
964    stack_frame_ix                  The index of the stack frame whose
965                                    function info should be returned.  If the
966                                    caller does not specifiy a value, this
967                                    function will set the value to 1 which is
968                                    the index of the caller's stack frame.  If
969                                    the caller is the wrapper function
970                                    "print_executing", this function will bump
971                                    it up by 1.
972    """
973
974    # If user wants default stack_frame_ix.
975    if stack_frame_ix is None:
976        func_name = sys._getframe().f_code.co_name
977        caller_func_name = sys._getframe(1).f_code.co_name
978        if caller_func_name.endswith(func_name[1:]):
979            stack_frame_ix = 2
980        else:
981            stack_frame_ix = 1
982
983    stack_frame = inspect.stack()[stack_frame_ix]
984
985    func_name = str(stack_frame[3])
986    if func_name == "?":
987        # "?" is the name used when code is not in a function.
988        func_name = "(none)"
989
990    if func_name == "<module>":
991        # If the func_name is the "main" program, we simply get the command
992        # line call string.
993        func_and_args = ' '.join(sys.argv)
994    else:
995        # Get the program arguments.
996        arg_vals = inspect.getargvalues(stack_frame[0])
997        function_parms = arg_vals[0]
998        frame_locals = arg_vals[3]
999
1000        args_list = []
1001        for arg_name in function_parms:
1002            # Get the arg value from frame locals.
1003            arg_value = frame_locals[arg_name]
1004            args_list.append(arg_name + " = " + repr(arg_value))
1005        args_str = "(" + ', '.join(map(str, args_list)) + ")"
1006
1007        # Now we need to print this in a nicely-wrapped way.
1008        func_and_args = func_name + " " + args_str
1009
1010    return sprint_time() + "Executing: " + func_and_args + "\n"
1011
1012###############################################################################
1013
1014
1015###############################################################################
1016def sprint_pgm_header(indent=0,
1017                      linefeed=1):
1018
1019    r"""
1020    Return a standardized header that programs should print at the beginning
1021    of the run.  It includes useful information like command line, pid,
1022    userid, program parameters, etc.
1023
1024    Description of arguments:
1025    indent                          The number of characters to indent each
1026                                    line of output.
1027    linefeed                        Indicates whether a line feed be included
1028                                    at the beginning and end of the report.
1029    """
1030
1031    loc_col1_width = col1_width + indent
1032
1033    buffer = ""
1034    if linefeed:
1035        buffer = "\n"
1036
1037    buffer += sindent(sprint_time() + "Running " + pgm_name + ".\n", indent)
1038    buffer += sindent(sprint_time() + "Program parameter values, etc.:\n\n",
1039                      indent)
1040    buffer += sprint_varx("command_line", ' '.join(sys.argv), 0, indent,
1041                          loc_col1_width)
1042    # We want the output to show a customized name for the pid and pgid but
1043    # we want it to look like a valid variable name.  Therefore, we'll use
1044    # pgm_name_var_name which was set when this module was imported.
1045    buffer += sprint_varx(pgm_name_var_name + "_pid", os.getpid(), 0, indent,
1046                          loc_col1_width)
1047    buffer += sprint_varx(pgm_name_var_name + "_pgid", os.getpgrp(), 0, indent,
1048                          loc_col1_width)
1049    userid_num = str(os.geteuid())
1050    try:
1051        username = os.getlogin()
1052    except OSError:
1053        if userid_num == "0":
1054            username = "root"
1055        else:
1056            username = "?"
1057    buffer += sprint_varx("uid", userid_num + " (" + username +
1058                          ")", 0, indent, loc_col1_width)
1059    buffer += sprint_varx("gid", str(os.getgid()) + " (" +
1060                          str(grp.getgrgid(os.getgid()).gr_name) + ")", 0,
1061                          indent, loc_col1_width)
1062    buffer += sprint_varx("host_name", socket.gethostname(), 0, indent,
1063                          loc_col1_width)
1064    try:
1065        DISPLAY = os.environ['DISPLAY']
1066    except KeyError:
1067        DISPLAY = ""
1068    buffer += sprint_varx("DISPLAY", DISPLAY, 0, indent,
1069                          loc_col1_width)
1070    # I want to add code to print caller's parms.
1071
1072    # __builtin__.arg_obj is created by the get_arg module function,
1073    # gen_get_options.
1074    try:
1075        buffer += ga.sprint_args(__builtin__.arg_obj, indent)
1076    except AttributeError:
1077        pass
1078
1079    if linefeed:
1080        buffer += "\n"
1081
1082    return buffer
1083
1084###############################################################################
1085
1086
1087###############################################################################
1088def sprint_error_report(error_text="\n",
1089                        indent=2):
1090
1091    r"""
1092    Return a string with a standardized report which includes the caller's
1093    error text, the call stack and the program header.
1094
1095    Description of args:
1096    error_text                      The error text to be included in the
1097                                    report.  The caller should include any
1098                                    needed linefeeds.
1099    indent                          The number of characters to indent each
1100                                    line of output.
1101    """
1102
1103    buffer = ""
1104    buffer += sprint_dashes(width=120, char="=")
1105    buffer += sprint_error(error_text)
1106    buffer += "\n"
1107    # Calling sprint_call_stack with stack_frame_ix of 0 causes it to show
1108    # itself and this function in the call stack.  This is not helpful to a
1109    # debugger and is therefore clutter.  We will adjust the stack_frame_ix to
1110    # hide that information.
1111    stack_frame_ix = 2
1112    caller_func_name = sprint_func_name(2)
1113    if caller_func_name.endswith("print_error_report"):
1114        stack_frame_ix += 1
1115    buffer += sprint_call_stack(indent, stack_frame_ix)
1116    buffer += sprint_pgm_header(indent)
1117    buffer += sprint_dashes(width=120, char="=")
1118
1119    return buffer
1120
1121###############################################################################
1122
1123
1124###############################################################################
1125def sprint_issuing(cmd_buf,
1126                   test_mode=0):
1127
1128    r"""
1129    Return a line indicating a command that the program is about to execute.
1130
1131    Sample output for a cmd_buf of "ls"
1132
1133    #(CDT) 2016/08/25 17:57:36 - Issuing: ls
1134
1135    Description of args:
1136    cmd_buf                         The command to be executed by caller.
1137    test_mode                       With test_mode set, your output will look
1138                                    like this:
1139
1140    #(CDT) 2016/08/25 17:57:36 - (test_mode) Issuing: ls
1141
1142    """
1143
1144    buffer = sprint_time()
1145    if test_mode:
1146        buffer += "(test_mode) "
1147    buffer += "Issuing: " + cmd_buf + "\n"
1148
1149    return buffer
1150
1151###############################################################################
1152
1153
1154###############################################################################
1155def sprint_pgm_footer():
1156
1157    r"""
1158    Return a standardized footer that programs should print at the end of the
1159    program run.  It includes useful information like total run time, etc.
1160    """
1161
1162    buffer = "\n" + sprint_time() + "Finished running " + pgm_name + ".\n\n"
1163
1164    total_time = time.time() - start_time
1165    total_time_string = "%0.6f" % total_time
1166
1167    buffer += sprint_varx(pgm_name_var_name + "_runtime", total_time_string)
1168    buffer += "\n"
1169
1170    return buffer
1171
1172###############################################################################
1173
1174
1175###############################################################################
1176def sprint(buffer=""):
1177
1178    r"""
1179    Simply return the user's buffer.  This function is used by the qprint and
1180    dprint functions defined dynamically below, i.e. it would not normally be
1181    called for general use.
1182
1183    Description of arguments.
1184    buffer                          This will be returned to the caller.
1185    """
1186
1187    return str(buffer)
1188
1189###############################################################################
1190
1191
1192###############################################################################
1193def sprintn(buffer=""):
1194
1195    r"""
1196    Simply return the user's buffer with a line feed.  This function is used
1197    by the qprint and dprint functions defined dynamically below, i.e. it
1198    would not normally be called for general use.
1199
1200    Description of arguments.
1201    buffer                          This will be returned to the caller.
1202    """
1203
1204    buffer = str(buffer) + "\n"
1205
1206    return buffer
1207
1208###############################################################################
1209
1210
1211###############################################################################
1212# In the following section of code, we will dynamically create print versions
1213# for each of the sprint functions defined above.  So, for example, where we
1214# have an sprint_time() function defined above that returns the time to the
1215# caller in a string, we will create a corresponding print_time() function
1216# that will print that string directly to stdout.
1217
1218# It can be complicated to follow what's being creaed by the exec statement
1219# below.  Here is an example of the print_time() function that will be created:
1220
1221# def print_time(*args):
1222#   s_funcname = "s" + sys._getframe().f_code.co_name
1223#   s_func = getattr(sys.modules[__name__], s_funcname)
1224#   sys.stdout.write(s_func(*args))
1225
1226# Here are comments describing the 3 lines in the body of the created function.
1227# Calculate the "s" version of this function name (e.g. if this function name
1228# is print_time, we want s_funcname to be "sprint_time".
1229# Put a reference to the "s" version of this function in s_func.
1230# Call the "s" version of this function passing it all of our arguments.
1231# Write the result to stdout.
1232
1233# func_names contains a list of all print functions which should be created
1234# from their sprint counterparts.
1235func_names = ['print_time', 'print_timen', 'print_error', 'print_varx',
1236              'print_var', 'print_vars', 'print_dashes', 'indent',
1237              'print_call_stack', 'print_func_name', 'print_executing',
1238              'print_pgm_header', 'print_issuing', 'print_pgm_footer',
1239              'print_error_report', 'print', 'printn']
1240
1241for func_name in func_names:
1242    if func_name == "print":
1243        continue
1244    # Create abbreviated aliases (e.g. spvar is an alias for sprint_var).
1245    alias = re.sub("print_", "p", func_name)
1246    pgm_definition_string = "s" + alias + " = s" + func_name
1247    if gen_print_debug:
1248        print(pgm_definition_string)
1249    exec(pgm_definition_string)
1250
1251for func_name in func_names:
1252    if func_name == "print_error" or func_name == "print_error_report":
1253        output_stream = "stderr"
1254    else:
1255        output_stream = "stdout"
1256    func_def = \
1257        [
1258            "def " + func_name + "(*args):",
1259            "  s_func_name = \"s\" + sys._getframe().f_code.co_name",
1260            "  s_func = getattr(sys.modules[__name__], s_func_name)",
1261            "  sys." + output_stream + ".write(s_func(*args))",
1262            "  sys." + output_stream + ".flush()"
1263        ]
1264    if func_name != "print":
1265        pgm_definition_string = '\n'.join(func_def)
1266        if gen_print_debug:
1267            print(pgm_definition_string)
1268        exec(pgm_definition_string)
1269
1270    # Now define "q" versions of each print function.
1271    func_def = \
1272        [
1273            "def q" + func_name + "(*args):",
1274            "  if __builtin__.quiet: return",
1275            "  s_func_name = \"s" + func_name + "\"",
1276            "  s_func = getattr(sys.modules[__name__], s_func_name)",
1277            "  sys." + output_stream + ".write(s_func(*args))",
1278            "  sys." + output_stream + ".flush()"
1279        ]
1280
1281    pgm_definition_string = '\n'.join(func_def)
1282    if gen_print_debug:
1283        print(pgm_definition_string)
1284    exec(pgm_definition_string)
1285
1286    # Now define "d" versions of each print function.
1287    func_def = \
1288        [
1289            "def d" + func_name + "(*args):",
1290            "  if not __builtin__.debug: return",
1291            "  s_func_name = \"s" + func_name + "\"",
1292            "  s_func = getattr(sys.modules[__name__], s_func_name)",
1293            "  sys." + output_stream + ".write(s_func(*args))",
1294            "  sys." + output_stream + ".flush()"
1295        ]
1296
1297    pgm_definition_string = '\n'.join(func_def)
1298    if gen_print_debug:
1299        print(pgm_definition_string)
1300    exec(pgm_definition_string)
1301
1302    # Now define "l" versions of each print function.
1303    func_def = \
1304        [
1305            "def l" + func_name + "(*args):",
1306            "  s_func_name = \"s" + func_name + "\"",
1307            "  s_func = getattr(sys.modules[__name__], s_func_name)",
1308            "  logging.log(getattr(logging, 'INFO'), s_func(*args))",
1309        ]
1310
1311    if func_name != "print_varx" and func_name != "print_var":
1312        pgm_definition_string = '\n'.join(func_def)
1313        if gen_print_debug:
1314            print(pgm_definition_string)
1315        exec(pgm_definition_string)
1316
1317    if func_name == "print":
1318        continue
1319
1320    # Create abbreviated aliases (e.g. pvar is an alias for print_var).
1321    alias = re.sub("print_", "p", func_name)
1322    pgm_definition_string = alias + " = " + func_name
1323    if gen_print_debug:
1324        print(pgm_definition_string)
1325    exec(pgm_definition_string)
1326
1327    # Create abbreviated aliases (e.g. qpvar is an alias for qprint_var).
1328    alias = re.sub("print_", "p", func_name)
1329    pgm_definition_string = "q" + alias + " = q" + func_name
1330    if gen_print_debug:
1331        print(pgm_definition_string)
1332    exec(pgm_definition_string)
1333
1334    # Create abbreviated aliases (e.g. dpvar is an alias for dprint_var).
1335    alias = re.sub("print_", "p", func_name)
1336    pgm_definition_string = "d" + alias + " = d" + func_name
1337    if gen_print_debug:
1338        print(pgm_definition_string)
1339    exec(pgm_definition_string)
1340
1341    # Create abbreviated aliases (e.g. lpvar is an alias for lprint_var).
1342    alias = re.sub("print_", "p", func_name)
1343    pgm_definition_string = "l" + alias + " = l" + func_name
1344    if gen_print_debug:
1345        print(pgm_definition_string)
1346    exec(pgm_definition_string)
1347
1348###############################################################################
1349