This issue tracker has been migrated to GitHub, and is currently read-only.
For more information, see the GitHub FAQs in the Python's Developer Guide.

classification
Title: Adding LTTng-UST tracing support
Type: enhancement Stage:
Components: Versions: Python 3.8
process
Status: open Resolution:
Dependencies: Superseder:
Assigned To: lukasz.langa Nosy List: Francis Deslauriers, cburroughs, cstratak, jcea, lukasz.langa, pdmccormick
Priority: normal Keywords: patch

Created on 2016-12-08 20:04 by Francis Deslauriers, last changed 2022-04-11 14:58 by admin.

Files
File name Uploaded Description Edit
0001-Add-LTTng-UST-probe-and-tracepoints.patch Francis Deslauriers, 2016-12-08 20:04 Add lttng-ust support patch v1
0002-LTTng-UST-tracing-tests.patch Francis Deslauriers, 2017-03-03 15:30 LTTng UST test patch v1 review
0003-Documentation-of-LTTng-UST-tracing-instrumentation.patch Francis Deslauriers, 2017-03-03 15:31 LTTng UST Documentation patch v1
bpo-28909-pyprobe-refactor-20180727.patch pdmccormick, 2018-07-27 06:38
Repositories containing patches
https://github.com/pdmccormick/cpython/tree/bpo-28909-pyprobe-refactor
Messages (14)
msg282733 - (view) Author: Francis Deslauriers (Francis Deslauriers) Date: 2016-12-08 20:04
This patch extends the tracing infrastructure to support LTTng UserSpace
Tracer. Using LTTng-UST, users would have access to a low overhead tracing 
done entirely from userspace.

Depending on the tracing configure option used (none, --with-dtrace or
--with-lttngust) macros will be expanded to probes and tracepoints of the
desired tracer if any. Only the needed instrumentation will be added to the
binary. This technique is used to different degrees by other projects like 
Qemu[1] and Node.js[2].

I attached a patch adding this feature. I tested the changes and the 
instrumentation on LTTng-UST and SystemTap on Ubuntu 16.04. I would 
appreciate if someone could test those changes on macOS and other
platforms supporting USDT probes.

[1]https://github.com/qemu/qemu/blob/master/configure#L4303
[2]https://github.com/nodejs/node/blob/master/configure#L811
msg284208 - (view) Author: Łukasz Langa (lukasz.langa) * (Python committer) Date: 2016-12-28 23:26
This looks promising but I don't know how to test it. Tests would be welcome, as well as some explanation what OS and kernel I need to use to test it out.

Why does your patch rename the DTrace provider from "python" to "cpython"? At this point, with release of Python 3.6, it's an incompatible change we can't really accept easily.
msg285074 - (view) Author: Francis Deslauriers (Francis Deslauriers) Date: 2017-01-09 21:16
Thanks Łukasz,
I will add tests following the example of the DTrace tests and update the Doc/howto/instrumentation.rst file to include this new information.

LTTng can be used  on all major Linux distros (Ubuntu, Debian, Fedora, etc.) either from distribution packages or compiled from source. It runs on kernels that came out after 2.6.27.

You are right, I should have explained why I changed the provider name. I changed it be as specific as possible to avoid potential name clash with other Python interpreters.
I will send an updated patch that keeps the old name given that it was already released.
msg288103 - (view) Author: Peter McCormick (pdmccormick) * Date: 2017-02-19 05:09
Fork at <https://github.com/pdmccormick/cpython/tree/bpo-28909-adding-lttng-ust> with Francis' original patch, plus a revert for the DTrace provider name change.

Here are instructions I used to try this out:

## LTTng installation

Full installation instructions for LTTng are available at <https://lttng.org/download/>. On Ubuntu 19.04 you can currently install LTTng v2.7 from the `universe` repository if it is enabled:

```shell
$ apt-get install lttng-tools lttng-modules-dkms liblttng-ust-dev babeltrace
```

## Building

Clone/fetch/checkout from <https://github.com/pdmccormick/cpython/tree/bpo-28909-adding-lttng-ust> and run:

```shell
$ ./configure --with-lttngust
$ make
```

## Tracing a session

LTTng operates around the concept of tracing selected userspace & kernelspace events of interest within the context of a session, so let's start one and run the instrumented interpreter to see what happens:

```shell
$ lttng create 'pysession'
$ lttng enable-event --userspace 'cpython:*'
$ lttng start
$ ./python -m this
$ lttng stop
$ lttng view | wc -l
48257
$ lttng view
[23:50:04.493873655] (+?.?????????) keflavik cpython:gc__start: { cpu_id = 1 }, { generation = 0 }
[23:50:04.493910472] (+0.000036817) keflavik cpython:gc__done: { cpu_id = 1 }, { collected = 0 }
[23:50:04.494281326] (+0.000370854) keflavik cpython:gc__start: { cpu_id = 1 }, { generation = 0 }
[23:50:04.494305307] (+0.000023981) keflavik cpython:gc__done: { cpu_id = 1 }, { collected = 0 }
[23:50:04.495031049] (+0.000725742) keflavik cpython:gc__start: { cpu_id = 1 }, { generation = 0 }
[23:50:04.495074272] (+0.000043223) keflavik cpython:gc__done: { cpu_id = 1 }, { collected = 0 }
[23:50:04.495403759] (+0.000329487) keflavik cpython:function__entry: { cpu_id = 1 }, { co_filename = "<frozen importlib._bootstrap>", co_name = "<module>", line_no = 8 }
[23:50:04.495405056] (+0.000001297) keflavik cpython:line: { cpu_id = 1 }, { co_filename = "<frozen importlib._bootstrap>", co_name = "<module>", line_no = 8 }
[23:50:04.495406486] (+0.000001430) keflavik cpython:line: { cpu_id = 1 }, { co_filename = "<frozen importlib._bootstrap>", co_name = "<module>", line_no = 25 }
[23:50:04.495407149] (+0.000000663) keflavik cpython:line: { cpu_id = 1 }, { co_filename = "<frozen importlib._bootstrap>", co_name = "<module>", line_no = 27 }
[23:50:04.495408921] (+0.000001772) keflavik cpython:line: { cpu_id = 1 }, { co_filename = "<frozen importlib._bootstrap>", co_name = "<module>", line_no = 35 }
[23:50:04.495409618] (+0.000000697) keflavik cpython:line: { cpu_id = 1 }, { co_filename = "<frozen importlib._bootstrap>", co_name = "<module>", line_no = 42 }
[23:50:04.495410775] (+0.000001157) keflavik cpython:line: { cpu_id = 1 }, { co_filename = "<frozen importlib._bootstrap>", co_name = "<module>", line_no = 44 }
[23:50:04.495412006] (+0.000001231) keflavik cpython:line: { cpu_id = 1 }, { co_filename = "<frozen importlib._bootstrap>", co_name = "<module>", line_no = 47 }
[23:50:04.495421990] (+0.000009984) keflavik cpython:function__entry: { cpu_id = 1 }, { co_filename = "<frozen importlib._bootstrap>", co_name = "_DeadlockError", line_no = 47 }
[23:50:04.495422496] (+0.000000506) keflavik cpython:line: { cpu_id = 1 }, { co_filename = "<frozen importlib._bootstrap>", co_name = "_DeadlockError", line_no = 47 }
[23:50:04.495423317] (+0.000000821) keflavik cpython:line: { cpu_id = 1 }, { co_filename = "<frozen importlib._bootstrap>", co_name = "_DeadlockError", line_no = 48 }
[23:50:04.495424559] (+0.000001242) keflavik cpython:function__return: { cpu_id = 1 }, { co_filename = "<frozen importlib._bootstrap>", co_name = "_DeadlockError", line_no = 48 }
[23:50:04.495468551] (+0.000043992) keflavik cpython:line: { cpu_id = 1 }, { co_filename = "<frozen importlib._bootstrap>", co_name = "<module>", line_no = 51 }
[23:50:04.495470096] (+0.000001545) keflavik cpython:function__entry: { cpu_id = 1 }, { co_filename = "<frozen importlib._bootstrap>", co_name = "_ModuleLock", line_no = 51 }
[23:50:04.495470570] (+0.000000474) keflavik cpython:line: { cpu_id = 1 }, { co_filename = "<frozen importlib._bootstrap>", co_name = "_ModuleLock", line_no = 51 }
[23:50:04.495471249] (+0.000000679) keflavik cpython:line: { cpu_id = 1 }, { co_filename = "<frozen importlib._bootstrap>", co_name = "_ModuleLock", line_no = 55 }
[23:50:04.495471746] (+0.000000497) keflavik cpython:line: { cpu_id = 1 }, { co_filename = "<frozen importlib._bootstrap>", co_name = "_ModuleLock", line_no = 57 }
...
```

The raw trace files will be written under `~/lttng-traces/pysession-$TIMESTAMP`. To clean them up afterwards, you can run:

```shell
$ lttng destroy
```

## GitHub

I would be happy to re-post this to GitHub issues if so desired.
msg288110 - (view) Author: Peter McCormick (pdmccormick) * Date: 2017-02-19 06:02
A few suggestions:

 * Disallow `--with-lttngust` on anything other than Linux (on macOS `configure` dies due to differences in acceptable `mktemp` arguments if you even attempt it)
 * Rename `cpython_inst.h` to `pytrace.h` and rename `pylttngust_probes.h` to `pytrace_lttngust_probes.h`
	- While we're at it, rename `pydtrace.h` to `pytrace_dtrace.h`, and other mentions of `PyDTrace_*` to `PyTrace_DTrace_*`?
 * Define a `WITH_TRACE` or `Py_TRACE` or similar preprocessor symbol 
 * Using that symbol, in `Python/ceval.c` ifdef-guard the static function prototypes and function calls
	- Otherwise when BOTH DTrace and LTTng-UST are disabled, Clang on macOS gives `warning: code will never be executed` warnings on the various arms of the `if (PyTraceEnabled(...))` statements, and GCC on Linux warn about unused variables `lineno`, `funcname` and `filename` in `pytrace_function_{entry,return}`, since the actual use of those variables as arguments is preprocessed out of existance

If everyone was in agreement, would it make sense to sequence this as first the generalization-renames to the existing DTrace/SystemTap code, and then recast the LTTng addition patch on top of those? I'd be happy to do this.

So, `PyTrace` or `PyTracing`?
msg288315 - (view) Author: Łukasz Langa (lukasz.langa) * (Python committer) Date: 2017-02-21 18:43
Thanks for working on this! A few thoughts.

1. Keep the existing names.

"PyTrace" is already a name in use for a different purpose. I understand the itch to make the name more "right" but I am in general not a fan of renaming "PyDTrace" to anything else now. It was a placeholder from day one (SystemTap uses it, too, after all). So, looking closer at the patch now I'd prefer us to keep all existing names and add LTTng as another alternative engine here. That will make the patch much shorter.

A nit: the name LTTng-UST is rather unfriendly, especially when used without the dash and in all lowercase characters. Given that we're using "dtrace" and "systemtap", it would be simpler to just use "lttng" (drop the "-ust").


2. DTrace vs SystemTap vs LTTng.

It's impossible to have DTrace and SystemTap at the same time, so it was natural to choose to auto-detect the engine. With LTTng it becomes less obvious what the configure options should be.

Should it be possible at all to have *both* LTTng and SystemTap compiled in at the same time? Does this make sense?

If yes, then keeping --with-dtrace and --with-lttng as separate options makes sense to me. If it doesn't, we should change the option to look like this: `--with(out)-dtrace=[=detect]`. This way people could pass the following:

    --without-dtrace (the default)
    --with-dtrace  (detects DTrace or SystemTap or LTTng, in that order)
    --with-dtrace=detect  (like the one above)
    --with-dtrace=dtrace  (assumes DTrace, fails if cannot proceed)
    --with-dtrace=systemtap  (assumes SystemTap, fails if cannot proceed)
    --with-dtrace=lttng  (assumes LTTng, fails if cannot proceed)  


3. Other questions.

> Clang on macOS gives `warning: code will never be executed` warnings on the various arms of the `if (PyTraceEnabled(...))` statements, and GCC on Linux warn about unused variables `lineno`, `funcname` and `filename` in `pytrace_function_{entry,return}`, since the actual use of those variables as arguments is preprocessed out of existance.

Do you get unused code warnings without your patch applied? I don't.


> I would be happy to re-post this to GitHub issues if so desired.

CPython is not using GitHub issues.
msg288489 - (view) Author: Francis Deslauriers (Francis Deslauriers) Date: 2017-02-23 21:53
I am finally having the time to work in this.

> A nit: the name LTTng-UST is rather unfriendly, especially when used without the dash and in all lowercase characters. Given that we're using "dtrace" and "systemtap", it would be simpler to just use "lttng" (drop the "-ust").
We can certainly drop the "-ust" and have the name in lowercase.

> It's impossible to have DTrace and SystemTap at the same time, so it was natural to choose to auto-detect the engine. With LTTng it becomes less obvious what the configure options should be.
> Should it be possible at all to have *both* LTTng and SystemTap compiled in at the same time? Does this make sense?
It's possible to have both SystemTap and LTTng in the same binary. LTTng-UST has a configure option `--with-sdt` to include a SystemTap SDT probe alongside each LTTng-UST tracepoint. I don't have a  specific usecase in mind but I can picture a setup where a binary is instrumented with both frameworks and the users either decide to use the low overhead tracing of LTTng or the versatile runtime aggregation of SystemTap depending on the problem they are trying to diagnose. So I think keeping both configure options makes sense.

> Do you get unused code warnings without your patch applied? I don't.
I am getting those errors too on Linux with GCC. I will make sure to fix them in the next round.

I am currently working on the tests and documentation and I hope to submit patches for review early next week.

Thank you,
Francis
msg288492 - (view) Author: Peter McCormick (pdmccormick) * Date: 2017-02-23 22:19
Hi Łukasz, thank you for the feedback!

> "PyTrace" is already a name in use for a different purpose. I understand the
> itch to make the name more "right" but I am in general not a fan of renaming
> "PyDTrace" to anything else now. It was a placeholder from day one (SystemTap
> uses it, too, after all). So, looking closer at the patch now I'd prefer us
> to keep all existing names and add LTTng as another alternative engine here.
> That will make the patch much shorter.

What about `PyProbe`? Given the multitude of tools and techniques in this space, wouldn't it be worthwhile to clarify things before adding this? I think conflating `dtrace` and `lttng` would only lead to more confusion for users as they really are distinct technologies.

Apart from the `--with{out)-dtrace` configure options, are these terms exposed to users anywhere else? I agree that those options shouldn't be changed now.
msg288896 - (view) Author: Francis Deslauriers (Francis Deslauriers) Date: 2017-03-03 15:30
> What about `PyProbe`? Given the multitude of tools and techniques in this space, wouldn't it be worthwhile to clarify things before adding this? I think conflating `dtrace` and `lttng` would only lead to more confusion for users as they really are distinct technologies.

I like the PyProbe name too. PyTracepoint could be another option.

Here is the tests patch. The tests are using the same test cases as the DTrace and SystemTap tests.
It still uses the same name as before and the tests were added to the existing test_dtrace.py file. I will send an updated version once we have the final name.
msg288897 - (view) Author: Francis Deslauriers (Francis Deslauriers) Date: 2017-03-03 15:31
Here is the documentation patch.
msg292074 - (view) Author: Charalampos Stratakis (cstratak) * Date: 2017-04-21 18:55
Just a small note here for the documentation patch.

yum is deprecated in Fedora, and dnf is now the default package manager, so the respective instructions for Fedora should reflect that.
msg301997 - (view) Author: Francis Deslauriers (Francis Deslauriers) Date: 2017-09-12 21:40
Hi all,
Is there anything I can do to move this patch-set forward?

@Charalampos, I will make sure to include this in the patch. Thank you.
msg321769 - (view) Author: Francis Deslauriers (Francis Deslauriers) Date: 2018-07-16 20:51
Hi all,

It seems that, as of right now, the thing blocking this patchset from
going forward is the name of the intrumentation point. 

Two naming approached were suggested:
	- Keeping PyDtrace*
	- Changing to PyProbe*

I prefer the PyProbe option as it's a more generic name and is not misleading
of the underlying tracing engine but if people prefer that we keep the PyDtrace
version let's go with that.
So, what should we go with?

I can easily update and rebase this patchset.

As an example of how this feature could be used, a colleague of mine gave a
talk[1] at PyCon Canada 2017 about tracing Python applications using this
patchset. He built a tool to visualize Python Logging, Python function calls
and Linux syscalls all in the same view. This was done using the existing
Python logger tracing of LTTng-UST, the LTTng kernel tracer and the CPython
LTTng-UST instrumentation of this patchset. Here is an asciinema[2] recording
used in the talk, it shows the tool in action.

[1]: https://youtu.be/gKmtmPqr6H8
[2]: https://asciinema.org/a/v20Hxnoh3lpzzz3FPmF86fNDS

Cheers!
Francis
msg322467 - (view) Author: Peter McCormick (pdmccormick) * Date: 2018-07-27 06:38
I would like to propose the following patch[0] which generalizes the `PyDTrace_*` definitions to a more generic `PyProbe` structure, in anticipation of including LTTng support side-by-side with the existing DTrace support.

A couple of argument types in `Include/pydtrace.h` were also changed to match those in `Include/pydtrace.d`. I can split that out to a separate, pre-PyProbe patch if that would be preferred.

Some of the `*_ENABLED()` calls were reorganized such that they will actually be invoked twice (specifically in `Python/ceval.c` were the enabled check was used prior to calling helper functions, which then eventually invoked the DTrace macros.) If this won't work, we could add a sequence of guarded-by-ifdef-instead-of-enabled calls to ensure that there will only ever be one instance of any given `PyDTrace_*_ENABLED()` call.

I've tested compilation on macOS with and without DTrace configured.

Feedback and comments would be most welcome!

Thanks,
Peter

[0] https://github.com/pdmccormick/cpython/commit/1e399f5ec381276b52e6a4f5a755fc0f23bd6d97
[1] https://github.com/pdmccormick/cpython/tree/bpo-28909-pyprobe-refactor
History
Date User Action Args
2022-04-11 14:58:40adminsetgithub: 73095
2018-07-27 06:38:18pdmccormicksetfiles: + bpo-28909-pyprobe-refactor-20180727.patch

messages: + msg322467
versions: + Python 3.8, - Python 3.7
2018-07-16 20:51:13Francis Deslaurierssetmessages: + msg321769
2017-09-12 21:40:24Francis Deslaurierssetmessages: + msg301997
2017-04-21 18:55:21cstrataksetnosy: + cstratak
messages: + msg292074
2017-04-21 18:20:54cburroughssetnosy: + cburroughs
2017-03-03 15:31:03Francis Deslaurierssetfiles: + 0003-Documentation-of-LTTng-UST-tracing-instrumentation.patch

messages: + msg288897
2017-03-03 15:30:34Francis Deslaurierssetfiles: + 0002-LTTng-UST-tracing-tests.patch

messages: + msg288896
2017-02-23 22:19:06pdmccormicksetmessages: + msg288492
2017-02-23 21:53:13Francis Deslaurierssetmessages: + msg288489
2017-02-21 18:43:49lukasz.langasetmessages: + msg288315
2017-02-19 06:02:47pdmccormicksetmessages: + msg288110
2017-02-19 05:09:50pdmccormicksetnosy: + pdmccormick

messages: + msg288103
hgrepos: + hgrepo367
2017-01-09 21:16:16Francis Deslaurierssetmessages: + msg285074
2016-12-28 23:26:49lukasz.langasetassignee: lukasz.langa
2016-12-28 23:26:44lukasz.langasetmessages: + msg284208
2016-12-16 18:02:22Francis Deslaurierssetnosy: + jcea
2016-12-08 20:08:48zach.waresetnosy: + lukasz.langa
2016-12-08 20:04:34Francis Deslaurierscreate