"Who called me" Issue

Rhino Developer
, , ,
#1

Hello here!

Here is my issue. I’m writing a logging function, which needs to know ‘Who called me’. I use inspect to to that. I want to know the filename, the function name and all the arguments. Here is the code:

import inspect
def GetCallerInfo():

stack            = inspect.stack()
functionName     = stack[2][3]
callerInfo       = stack[2][0]
f_code           = callerInfo.f_code
completeFilename = f_code.co_filename

# Remove the .py extension from filename
filename         = os.path.basename(completeFilename)[0:-3] 

f_back           = callerInfo.f_back

f_locals         = f_back.f_locals
args             = f_locals.items()
    
argsCount        = f_code.co_argcount
args             = args[0:argsCount]

return filename, functionName, args

This works well in debug mode, after having used the play button and having set at least 1 break point at some place. After that, I always get the correct answer, debugging or not. However, if I use that without having done any debugging before (play button without any break point), the ‘args’ output fails. It looks like that

print args → [(‘name’, ‘main’), (‘exit’, <System.Action object at 0x000000000000009E [System.Action]>), (‘file’, ‘C:\Users\User\Documents\Job\Bitbucket\python\Buttons\Button_Load.py’)]

In debug mode with a break point (and thereafter), what I get is like:

print args → [(‘param1’, value1), (‘param2’, ‘string2’), (‘param3’, False)]

Any idea what is going on? Is there a clean way to do that? Or at least tell Rhino “Yes I have debugged the stuff using a break point” without doing so?

Thank you!

Alexandre

Using locals() duplicates function arguments
#2

Hello,

I wonder whether you need to look further up or down the stack to find the information you are looking for because there is some python going on to operate the play button…? Can you print the whole stack and find the information you want?

You could use a simple decorator to get the called function and arguments but I don’t know how to get the caller.

#3

Hello,

Yes, I did look up & down the stack. The information is nowhere in it, unfortunately.

Thanks!

#4

Hello,

You say you want the arguments, which I understand to mean the arguments used to call the function (called or calling/outer?) but you are returning the locals() dictionary from the outer scope - is that what you want ?

The output you are getting looks very much like the locals() dictionary in the base scope of a python file, but mine is much much longer :

if __name__ == '__main__':
   print locals()

{'__name__': '__main__', 'exit': <System.Action object at 0x000000000000006C [System.Action]>, '__file__': 'C:\\Users\\knapp\\AppData\\Local\\Temp\\TempScript.py', '__builtins__': {'long': <type 'long'>, 'AttributeError': <type 'exceptions.AttributeError'>, 'tuple': <type 'tuple'>, 'type': <type 'type'>, 'Exception': <type 'exceptions.Exception'>, 'locals': <built-in function locals>, 'help': <built-in function help>, 'ImportError': <type 'exceptions.ImportError'>, 'float': <type 'float'>, 'TypeError': <type 'exceptions.TypeError'>, 'NotImplemented': NotImplemented, '__debug__': True, 'getattr': <built-in function getattr>, 'bool': <type 'bool'>, 'set': <type 'set'>, 'slice': <type 'slice'>, 'all': <built-in function all>, 'map': <built-in function map>, 'chr': <built-in function chr>, 'dict': <type 'dict'>, 'super': <type 'super'>, 'len': <built-in function len>, 'issubclass': <built-in function issubclass>, 'range': <built-in function range>, 'Ellipsis': Ellipsis, '__import__': <built-in function __import__>, 'unicode': <type 'str'>, 'Warning': <type 'exceptions.Warning'>, 'list': <type 'list'>, 'int': <type 'int'>, 'any': <built-in function any>, 'True': True, 'object': <type 'object'>, 'ValueError': <type 'exceptions.ValueError'>, 'globals': <built-in function globals>, 'str': <type 'str'>, 'hasattr': <built-in function hasattr>, 'buffer': <type 'buffer'>, 'file': <type 'file'>, 'isinstance': <built-in function isinstance>, 'False': False, 'frozenset': <type 'frozenset'>, 'NameError': <type 'exceptions.NameError'>, 'basestring': <type 'basestring'>, 'xrange': <type 'xrange'>, 'classmethod': <type 'classmethod'>, 'dir': <built-in function dir>, 'repr': <built-in function repr>, 'property': <type 'property'>, 'complex': <type 'complex'>, 'enumerate': <type 'enumerate'>, 'next': <built-in function next>, 'oct': <built-in function oct>, 'open': <built-in function open>, 'ord': <built-in function ord>, 'pow': <built-in function pow>, 'print': <built-in function print>, 'raw_input': <built-in function raw_input>, 'reduce': <built-in function reduce>, 'reload': <built-in function reload>, 'round': <built-in function round>, 'setattr': <built-in function setattr>, 'sorted': <built-in function sorted>, 'sum': <built-in function sum>, 'unichr': <built-in function unichr>, 'vars': <built-in function vars>, 'zip': <built-in function zip>, 'abs': <built-in function abs>, 'apply': <built-in function apply>, 'bin': <built-in function bin>, 'callable': <built-in function callable>, 'coerce': <built-in function coerce>, 'compile': <built-in function compile>, 'cmp': <built-in function cmp>, 'delattr': <built-in function delattr>, 'divmod': <built-in function divmod>, 'eval': <built-in function eval>, 'execfile': <built-in function execfile>, 'filter': <built-in function filter>, 'format': <built-in function format>, 'hash': <built-in function hash>, 'hex': <built-in function hex>, 'id': <built-in function id>, 'input': <built-in function input>, 'intern': <built-in function intern>, 'iter': <built-in function iter>, 'max': <built-in function max>, 'min': <built-in function min>, 'bytes': <type 'bytes'>, 'bytearray': <type 'bytearray'>, 'memoryview': <type 'memoryview'>, 'reversed': <type 'reversed'>, 'staticmethod': <type 'staticmethod'>, 'BaseException': <type 'exceptions.BaseException'>, 'GeneratorExit': <type 'exceptions.GeneratorExit'>, 'SystemExit': <type 'exceptions.SystemExit'>, 'KeyboardInterrupt': <type 'exceptions.KeyboardInterrupt'>, 'StopIteration': <type 'exceptions.StopIteration'>, 'StandardError': <type 'exceptions.StandardError'>, 'BufferError': <type 'exceptions.BufferError'>, 'ArithmeticError': <type 'exceptions.ArithmeticError'>, 'FloatingPointError': <type 'exceptions.FloatingPointError'>, 'OverflowError': <type 'exceptions.OverflowError'>, 'ZeroDivisionError': <type 'exceptions.ZeroDivisionError'>, 'AssertionError': <type 'exceptions.AssertionError'>, 'EnvironmentError': <type 'exceptions.EnvironmentError'>, 'IOError': <type 'exceptions.IOError'>, 'OSError': <type 'exceptions.OSError'>, 'WindowsError': <type 'exceptions.WindowsError'>, 'EOFError': <type 'exceptions.EOFError'>, 'LookupError': <type 'exceptions.LookupError'>, 'IndexError': <type 'exceptions.IndexError'>, 'KeyError': <type 'exceptions.KeyError'>, 'MemoryError': <type 'exceptions.MemoryError'>, 'UnboundLocalError': <type 'exceptions.UnboundLocalError'>, 'ReferenceError': <type 'exceptions.ReferenceError'>, 'RuntimeError': <type 'exceptions.RuntimeError'>, 'NotImplementedError': <type 'exceptions.NotImplementedError'>, 'SyntaxError': <type 'exceptions.SyntaxError'>, 'IndentationError': <type 'exceptions.IndentationError'>, 'TabError': <type 'exceptions.TabError'>, 'SystemError': <type 'exceptions.SystemError'>, 'UnicodeError': <type 'exceptions.UnicodeError'>, 'UnicodeDecodeError': <type 'exceptions.UnicodeDecodeError'>, 'UnicodeEncodeError': <type 'exceptions.UnicodeEncodeError'>, 'UnicodeTranslateError': <type 'exceptions.UnicodeTranslateError'>, 'DeprecationWarning': <type 'exceptions.DeprecationWarning'>, 'PendingDeprecationWarning': <type 'exceptions.PendingDeprecationWarning'>, 'RuntimeWarning': <type 'exceptions.RuntimeWarning'>, 'SyntaxWarning': <type 'exceptions.SyntaxWarning'>, 'UserWarning': <type 'exceptions.UserWarning'>, 'FutureWarning': <type 'exceptions.FutureWarning'>, 'ImportWarning': <type 'exceptions.ImportWarning'>, 'UnicodeWarning': <type 'exceptions.UnicodeWarning'>, 'BytesWarning': <type 'exceptions.BytesWarning'>, 'None': None, '__doc__': 'Provides access to commonly used built-in functions, exception objects, etc...', '__package__': None, '__name__': '__builtin__'}, 'inspect': <module 'inspect' from 'C:\Program Files\Rhino 7\Plug-ins\IronPython\Lib\inspect.py'>, 'sub': <function sub at 0x000000000000006D>, 'main': <function main at 0x000000000000006E>}
#5

Hi Alexandre,

I’m also looking into this, from the link in your other topic (Using locals() duplicates function arguments). I’m not sure I completely understand how GetCallerInfo() is supposed to be used, mostly because as @Dancergraham mentions it’s not clear which scope it is actually looking at. However, I’ve modified it a bit to something that I think is what you want, and it seems to be working here, whether I run in normal mode or debug mode first.

import inspect
import os

def GetCallerInfo():
    outerframes = inspect.getouterframes(inspect.currentframe(), 0)
    try:
        callerInfo = outerframes[1][0]
        try:
            f_code = callerInfo.f_code
            functionName = f_code.co_name
            completeFilename = f_code.co_filename
    
            # Remove the .py extension from filename
            filename         = os.path.basename(completeFilename)[0:-3] 
     
            f_locals         = callerInfo.f_locals
            args             = f_locals.items()
              
            argsCount        = f_code.co_argcount
            args             = args[0:argsCount]
        finally:
            del callerInfo
    finally:
        del outerframes

    return filename, functionName, args

def func(argA="1", argB=2):
    print GetCallerInfo()
    print(locals())

def func2():
    print GetCallerInfo()
    func()

func2()

('TempScript', 'func2', [])
('TempScript', 'func', [('argA', '1'), ('argB', 2)])
{'argA': '1', 'argB': 2}

The try/finally and del outerframes lines are based on a note in Python’s doc.

It sounds like you would be better served by a slightly different approach, with a decorator to add to the functions you want to debug, rather than a magic function inside the function’s body that will dig into the interpreter’s stack. I tried this snippet and it worked for me, you could modify it to also log the filename:

#6

Hi Pierre,

Your different approach seems to work for me too; this is exactly what I was looking for! Using this, I no longer need to call “locals()”. So, as long as my use case is concerned, both issues are solved.

Thank you very much!

Alexandre

#7

Hi!

I’ve spoken a little too fast: I still have to issues with the decorator approach!

1- Without modification, I dont have access to variable type. I guess the correction should not be too complicated, but as is, the type is always string

2- Refering to the example I posted in the other thread, this gives the unmodified values of arguments (0, True); I need to record the modified values(1, False) (These values comes from user input)

In a sense, using locals() is perfect since it gives the modified values.

Here is what Im trying to do; Record a sequence of different function calls by a user. Then be able to play it back automatically, in the same order, using eval(). So I need to record the file, function, all arguments and their modified values.

Going back to your original example, I added arguments to func2:

def GetCallerInfo():
    outerframes = inspect.getouterframes(inspect.currentframe(), 0)
    try:
        callerInfo = outerframes[1][0]
        try:
            f_code = callerInfo.f_code
            functionName = f_code.co_name
            completeFilename = f_code.co_filename
    
            # Remove the .py extension from filename
            filename         = os.path.basename(completeFilename)[0:-3] 
     
            f_locals         = callerInfo.f_locals
            args             = f_locals.items()
              
            argsCount        = f_code.co_argcount
            args             = args[0:argsCount]
        finally:
            del callerInfo
    finally:
        del outerframes

    return filename, functionName, args

def func(argA="1", argB=2):
    print GetCallerInfo()
    print(locals())

def func2(argA="3", argB=4):
    #locals()
    print GetCallerInfo()
    func()

func2()

('Test_Locals2', 'func2', [('__name__', '__main__'), ('exit', <System.Action object at 0x000000000000006C [System.Action]>)])
('Test_Locals2', 'func', [('argA', '1'), ('argB', 2)])
{'argA': '1', 'argB': 2}

Now, if I uncomment #locals() in func2, I get the expected result. It seems that using locals() is necessary in order to wake up the inspect module, even if I dont use it directly.

This brings me to another question: If I uncomment locals() in func2 and call it in non-debug mode, can I be confident there wont be any interference between actual arguments and the duplicates? (ClosureCell variables?) Hard to say since in non-debug I dont see anything! I want to be sure im recording the modified version. Could I know without “hope & pray”?

Thank you again!

Alexandre

#8

I’ve tried every combination of debug and normal run without and with locals() calls that I could think of, and I always get the expected result with your script:

('testlocals', 'func2', [('argA', '3'), ('argB', 4)])
('testlocals', 'func', [('argA', '1'), ('argB', 2)])
{'argA': '1', 'argB': 2}

I don’t know why you are getting these differences, unfortunately is seems like this is one of those cases where the quirks of IronPython get too difficult to deal with. I think you should try not to rely on stack introspection in IronPython in an automated framework.

Regarding what you are trying to do, I would also stay very far away from eval. There are way too many ways that recording and replaying Python code execution using strings can go wrong – just for one of them, what are you going to do about values that do not serialize into a string?

Instead, I would write a decorator that modifies the input function so that it copies and stores the arg dict before each call, and add a reference to the function. There are still ways this can go wrong (what if the function is modified between record and replay? I don’t know if you can copy a function easily in Python at runtime), and if you are not careful the Garbage Collector is going to hate you and memory usage will be very high. Use this sparingly on high-level functions only, be sure that copy works and the arguments you are passing, and delete any reference that becomes unused.

How about something like this:

from copy import deepcopy

HISTORY = []

def record(func, store):
    def wrapper(*args, **kwargs):
        store.append([func, deepcopy(args), deepcopy(kwargs)])
        func(*args, **kwargs)
    return wrapper
    
def recordto(store):
    return lambda func: record(func, store)

@recordto(HISTORY)
def func(arg1=1, arg2=False, *args, **kwargs):
    print(arg1, arg2, args, kwargs)

func()
func(3, [2, 1], arg1=0)

print(HISTORY)

def replay(history, range=slice(None)):
    for rec in history[range]:
        rec[0](*rec[1], **rec[2])

replay(HISTORY, slice(1))
replay(HISTORY)

This will record the unmodified values of the arguments, but I think this is what you want for replay. Any modification that happens inside the function will happen again when you replay the function.

#9

Thanks for this answer!

This might be what I need, but I have to adapt it to meet exactly my needs.

1- I need the modified argument values (I mean, modified after function call; inside the function).
3- The recording has to saved on disk, to be human readable & human modificable

For the moment, I’m using eval() since it allows me, at playback, to call functions coming from different files. All data is then saved (and read at playback) in a .xml file for need #3. I’m far from being python expert, so I believe you when you suggest staying far away from eval(). But I dont fully understand why. What makes me believe that it could be acceptable here is:

A) The range of values to record is very limited. The variable types also are limited: strings, floats, ints and 3d points. The variable type is recorded; At playback, they are casted before the eval() call
B) The recording is done after the actual functions have finished their job. The values are then modified and we know the function has worked with those values.
C) The users are not only powerusers: they are all in the company. Nobody outside will use that.
D) All this is done to make operations faster; an occasional fail is not a big deal.

About getting the expected result with and without locals(): here is what I get. Using locals(); it always work. Without locals() and with a breakpoint, it works. If I remove the breakpoint it still works. However, If I close Rhino a get a fresh one, without any break point, I get the bad local variables.

Otherwise, I guess everything is doable using the decorator, but I dont know yet how a could write the History list on disk in a way that makes sense.

Thank you!

#10

Hello,

It sounds like a combination of a decorator to record the calling function and arguments plus an explicit logging step inside the function is a good solution. If you think the work of the function might fail you could enclose the key portions in a try...except...finally... bloc, putting the logging step in the finally section for instance so it will log whatever the outcome : success or fail.

#11

Hello Graham,

I think you’re right, the use of a decorator and an adapted recording function is far prettier than the use of the call stack. However, I still have the problem of recording unmodified arguments when I need modified ones. I still dont see how record modified, since the decoration is done after the actual function, and the variable type of those arguments are immutable. I would need to pass arguments by reference.

The reason why I need modified value is the following. Im trying to record user actions. By default, arguments are set to None. In the function, all arguments set to None are asked to the user for a value. Then at replay, the recorded value are set; no user input is necessary.

Do you have an idea of how I could do that?

Thank you!

Alexandre

#12

Well the decorator “wraps” the called function so if it logs to the same place as the called function then you will see first the decorator log (including any arguments included with the call) and then the modified values logged by the function so you have all the info you need…?

#13

Inside the called functions, Im able to log everything except the arguments (as shown in previous messages), since the call stack is non reliable.

From the decorator, I also can log everything except the modified arguments.

Is there a way to get a dict/structure/list of arguments, inside the called function? From StackOverflow, I see answers telling to use locals(). It indeed does exactly what I need, but then I get an other issue: Using locals() duplicates function arguments

Thanks!

#14

You could split your function in multiple parts: one that deals with getting the inputs from the user (it doesn’t even need arguments for these), and one that does not modify its arguments and creates the geometry. The first one calls the second one when it’s done, or you can make a parent function that will call 1 and 2 in order. Record calls to function 2 only.

Relying on strings and prints in that case doesn’t sound as dangerous as I initially thought. Sounds like you are basically using this recorder to write a valid Python file that is first hand sanitized then run. Running python your_recorded_actions.py should be easier to debug than an eval call on that file but that all depends on your setup.

Recording the history with the decorator, then writing some code to print that into a nicely formatted Python file sounds like a good strategy for all this. You could also skip the part that copies the Python objects and directly write to a file (maybe using Python logging module with custom loggers to handle the formatting more easily?).

#15

Oh! This time I think the setup is complete, using those missing links (splitting functions & building a python file - I originally recorded to an .xml file). Thank you very much for listening to my story. Im trying all this and let you know how it goes!

Alexandre

1 Like