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