[lttng-dev] LTTng enable-event performance issue during active session - Kramer, Zach via lttng-dev

From: "Kramer, Zach via lttng-dev" <lttng-dev@lists.lttng.org>
To: lttng-dev <lttng-dev@lists.lttng.org>
Subject: [lttng-dev] LTTng enable-event performance issue during active session
Date: Tue, 26 Sep 2023 12:27:17 +0000	[thread overview]
Message-ID: <SN6PR06MB426922F9DBACE81D0C6B66A591C3A@SN6PR06MB4269.namprd06.prod.outlook.com> (raw)

[-- Attachment #1.1: Type: text/plain, Size: 2093 bytes --]

Hi,

I am observing a performance issue with regards to enabling events while a session is active and was wondering if this is expected.

LTTng versions:

  *   lttng-tools: 2.13.9
  *   lttng-ust: 2.13.6

Steps to reproduce:

  1.  Ensure many userspace tracepoints are available in `lttng list -u` e.g. 100
  2.  Create a new session
  3.  Start session
  4.  Enable new events on session

The time it takes to enable each new event has increasing cost e.g.

  1.  Event 1: 1ms
  2.  Event 100: 15ms
  3.  Event 1000: 150ms
  4.  --> in total about 1.5 minutes to enable 1000 events

If either:

  1.  No userspace tracepoints are available
  2.  Or session is not started until after the events are enabled

Then the time it takes to enable new events is constant (e.g. 1ms).

Below is a bash script demonstrating this behavior:
# Pre-requisite: have many userspace tracepoints available

lttng create foo
lttng enable-channel -u -s foo bar
lttng start foo

total_t1=$(date +%s%3N);

for i in {1..100}
do
        t1=$(date +%s%3N);
        lttng enable-event -u lttng_iter_$i -s foo -c bar > /dev/null
        t2=$(date +%s%3N);
        echo "Event #$i took $((t2-t1)) ms"
done

total_t2=$(date +%s%3N);

echo "----------------------------------------------------"
echo "Enabling events on active session took $((total_t2-total_t1)) ms"
echo "----------------------------------------------------"

lttng destroy foo

lttng create foo
lttng enable-channel -u -s foo bar

total_t1=$(date +%s%3N);

for i in {1..100}
do
        t1=$(date +%s%3N);
        lttng enable-event -u lttng_iter_$i -s foo -c bar > /dev/null
        t2=$(date +%s%3N);
        echo "Event #$i took $((t2-t1)) ms"
done

total_t2=$(date +%s%3N);

echo "----------------------------------------------------"
echo "Enabling events on inactive session took $((total_t2-total_t1)) ms"
echo "----------------------------------------------------"

lttng destroy foo

Is this reproducible for you? Any insight is appreciated.

Many thanks,
Zach

[-- Attachment #1.2: Type: text/html, Size: 18674 bytes --]

[-- Attachment #2: Type: text/plain, Size: 156 bytes --]

_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev