Mailing List Archive

Do you ever use ceval.c's LLTRACE feature?
Hi everyone,

I'm looking to improve the output of the interpreter's LLTRACE feature to make it more understandable. This "feature" is undocumented, but it prints out the opcode and oparg of every bytecode instruction executed, along with some info about stack operations, whenever you've built with Py_DEBUG and the name `__ltrace__` is defined in the module.

I've found this useful for debugging bits of the compiler and bytecode interpreter. For example, if I make some tweak that instroduces an off-by-one error, by default I get a segfault or a rather unhelpful assertion failure at `assert(EMPTY())` or `assert(STACK_LEVEL() <= frame->f_code->co_stacksize)` or similar, at best, with no inducation as to where or why that assertion is failing. But if I enable `__ltrace__` by either setting `__ltrace__=1` in some module or by manually setting `lltrace=1;` in the c code, I can follow what was happening in the interpreter just before the crash.

I'd like the output in that scenario to be a bit more helpful. I propose printing opcode names rather than decimal digits, and printing out the name of the current function whenever a stack frame begins executing. I also proprose to print out the full stack contents (almost never very deep) before each bytecode, rather than printing the state piecemeal at each PUSH/POP/STACK_ADJUST macro. I opened issue https://github.com/python/cpython/issues/91462 and PR https://github.com/python/cpython/pull/91463

I later found that this had been explored before by https://github.com/python/cpython/issues/69757, and there was a suggestion that this could be folded into a more generalized bytecode-level tracing feature that is pluggable with python code, similar to sys.settrace(). I would tend to think "YAGNI" -- lltrace is a feature for debugging the c internals of the interpreter, and there are already separate existing features like the `trace` module for tracing through Python code with different goals. I appreciate the simplicity of printf statements at the c level -- it feels more trustworthy than adding a complicated extra feature involving python calls and global state. It's as if I just littered the code with my own debugging print statements, but re-usable and better.

I see no documentation anywhere, and there's only one test case in test_lltrace, just testing that there's no segfault. Looking back through the git history, I see that the basic `printf("%d: %d, %d\n", ...);` format goes back to 1990: https://github.com/python/cpython/blob/3f5da24ea304e674a9abbdcffc4d671e32aa70f1/Python/ceval.c#L696-L710

I'm essentially writing to ask: how do you use lltrace? Does anyone rely on the particular format of the output? Would some of these improvements be helpful to you? What else could make it more helpful?

Thanks,
Dennis Sweeney
_______________________________________________
Python-Dev mailing list -- python-dev@python.org
To unsubscribe send an email to python-dev-leave@python.org
https://mail.python.org/mailman3/lists/python-dev.python.org/
Message archived at https://mail.python.org/archives/list/python-dev@python.org/message/DELHX3N5PCZDWIK2DLU5JDG6JREQ42II/
Code of Conduct: http://python.org/psf/codeofconduct/
Re: Do you ever use ceval.c's LLTRACE feature? [ In reply to ]
Hi Dennis,

It's been a while since I've used this code, but in the early days it was
indispensible. I think you have the right ideas on making it more useful
now that we're hacking on the bytecode again. Since lltrace is most useful
when the bytecode interpreter is somehow faulty, it doesn't make much sense
IMO to extend it with Python code, so indeed YAGNI on that proposal.

Since this will be useful only to a small audience, don't put too much
effort in it, but I'm sure that whatever effort you do put in it will be
much appreciated.

--Guido

On Thu, Apr 14, 2022 at 3:29 PM Dennis Sweeney <sweeney.dennis650@gmail.com>
wrote:

> Hi everyone,
>
> I'm looking to improve the output of the interpreter's LLTRACE feature to
> make it more understandable. This "feature" is undocumented, but it prints
> out the opcode and oparg of every bytecode instruction executed, along with
> some info about stack operations, whenever you've built with Py_DEBUG and
> the name `__ltrace__` is defined in the module.
>
> I've found this useful for debugging bits of the compiler and bytecode
> interpreter. For example, if I make some tweak that instroduces an
> off-by-one error, by default I get a segfault or a rather unhelpful
> assertion failure at `assert(EMPTY())` or `assert(STACK_LEVEL() <=
> frame->f_code->co_stacksize)` or similar, at best, with no inducation as to
> where or why that assertion is failing. But if I enable `__ltrace__` by
> either setting `__ltrace__=1` in some module or by manually setting
> `lltrace=1;` in the c code, I can follow what was happening in the
> interpreter just before the crash.
>
> I'd like the output in that scenario to be a bit more helpful. I propose
> printing opcode names rather than decimal digits, and printing out the name
> of the current function whenever a stack frame begins executing. I also
> proprose to print out the full stack contents (almost never very deep)
> before each bytecode, rather than printing the state piecemeal at each
> PUSH/POP/STACK_ADJUST macro. I opened issue
> https://github.com/python/cpython/issues/91462 and PR
> https://github.com/python/cpython/pull/91463
>
> I later found that this had been explored before by
> https://github.com/python/cpython/issues/69757, and there was a
> suggestion that this could be folded into a more generalized bytecode-level
> tracing feature that is pluggable with python code, similar to
> sys.settrace(). I would tend to think "YAGNI" -- lltrace is a feature for
> debugging the c internals of the interpreter, and there are already
> separate existing features like the `trace` module for tracing through
> Python code with different goals. I appreciate the simplicity of printf
> statements at the c level -- it feels more trustworthy than adding a
> complicated extra feature involving python calls and global state. It's as
> if I just littered the code with my own debugging print statements, but
> re-usable and better.
>
> I see no documentation anywhere, and there's only one test case in
> test_lltrace, just testing that there's no segfault. Looking back through
> the git history, I see that the basic `printf("%d: %d, %d\n", ...);` format
> goes back to 1990:
> https://github.com/python/cpython/blob/3f5da24ea304e674a9abbdcffc4d671e32aa70f1/Python/ceval.c#L696-L710
>
> I'm essentially writing to ask: how do you use lltrace? Does anyone rely
> on the particular format of the output? Would some of these improvements be
> helpful to you? What else could make it more helpful?
>
> Thanks,
> Dennis Sweeney
> _______________________________________________
> Python-Dev mailing list -- python-dev@python.org
> To unsubscribe send an email to python-dev-leave@python.org
> https://mail.python.org/mailman3/lists/python-dev.python.org/
> Message archived at
> https://mail.python.org/archives/list/python-dev@python.org/message/DELHX3N5PCZDWIK2DLU5JDG6JREQ42II/
> Code of Conduct: http://python.org/psf/codeofconduct/
>


--
--Guido van Rossum (python.org/~guido)
*Pronouns: he/him **(why is my pronoun here?)*
<http://feministing.com/2015/02/03/how-using-they-as-a-singular-pronoun-can-change-the-world/>
Re: Do you ever use ceval.c's LLTRACE feature? [ In reply to ]
Hi,

In 2017, I proposed to document the feature, but nobody was volunteer
to write the doc (issue still open):
https://bugs.python.org/issue25571

I added a bare minimum mention of this feature in the "Python Debug
Build" documentation:
https://docs.python.org/dev/using/configure.html#python-debug-build

A bug was fixed in 2018, so it has at least one user :-)
https://bugs.python.org/issue34113

In 2017, adding an API to trace instructions with sys.settrace() was
discussed, but the idea got rejected:

* https://bugs.python.org/issue29400
* https://mail.python.org/pipermail/python-dev/2017-September/149632.html

IMO it would be more flexible than the current "lltrace"
implementation which hardcode writing bytecode into C stdout stream
which is not convenient and cannot be easily redirected. I have no
idea if it would be possible to provide an *efficient* implementation
of such hook in ceval.c, even if it's only implemented in debug build.

Victor
_______________________________________________
Python-Dev mailing list -- python-dev@python.org
To unsubscribe send an email to python-dev-leave@python.org
https://mail.python.org/mailman3/lists/python-dev.python.org/
Message archived at https://mail.python.org/archives/list/python-dev@python.org/message/M6R6EWL2FS5SZC4A3ZDIPZH2LI6G4TFO/
Code of Conduct: http://python.org/psf/codeofconduct/