Re: [lttng-dev] LTTng enable-event performance issue during active session

2023-10-05 Thread Kienan Stewart via lttng-dev

Hi Zach

apologies for the delay in replying to your question.

On 2023-09-26 08:27, Kramer, Zach via lttng-dev wrote:

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.



I'm able to reproduce what you're seeing, and it's not completely 
unexpected based on my understanding of the architecture of lttng.


When a session is active and an event rule is enabled/disabled, the 
sessiond will notify each of the registered applications of the event 
rule state changes. This communication is going through either unix or 
tcp sockets, and that portion of the protocol seems to struggle with 
many small changes as the protocol to communicate the changes doesn't 
support batching.


Enabling multiple events in a single call reduces some of the overhead, 
but the changes will still be communicated serially. This means a single 
call activating thousands events can still take a long time to process 
(eg. `lttng enable-event -s foo -c bar -u tp0,tp1,...,tpN`)


Using glob patterns or `--all` will be significantly faster as the UST 
applications can digest those types of event rule changes with a single 
set of messages. In cases where you want most but not all events, 
flipping the logic to enable "*" but add events or patterns to omit with 
"--exclude" is going to be a better strategy.


Do you have cases where you need to activate many of events but which 
couldn't be covered by using glob patterns and/or exclusions?


thanks,
kienan


Many thanks,

Zach


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

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


Re: [lttng-dev] What is DEFINE_LTTNG_UST_SIGBUS_STATE for and other beginner questions

2023-10-05 Thread Kienan Stewart via lttng-dev

Hi Chris,

glad that you got it figured out! I created an issue based on your 
feedback. https://bugs.lttng.org/issues/1393


thanks,
kienan


On 2023-10-05 15:40, Christopher Harvey wrote:

I got this one figured out. I used strace -fp  -trace=connect on the 
target app to see why the connect was failing and it turns out there was a mismatch 
between sessiond's apps-socket paths and libust's.

time to review my build environment I guess. It's very possible my docker 
container's path environment variables are non-standard.

If I had a tiny bit of feedback to provide it would be to print out the errno 
and paths in the connect/bind commands in the DBG commands. I had to bust out 
strace to get that info. Small problem, but it could have saved me a few hours 
and some mailing list messages.

Thank you for making this nice looking software available for free. Looking 
forward to playing with it some more.

-Chris

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


Re: [lttng-dev] What is DEFINE_LTTNG_UST_SIGBUS_STATE for and other beginner questions

2023-10-05 Thread Christopher Harvey via lttng-dev
I got this one figured out. I used strace -fp  -trace=connect on the 
target app to see why the connect was failing and it turns out there was a 
mismatch between sessiond's apps-socket paths and libust's.

time to review my build environment I guess. It's very possible my docker 
container's path environment variables are non-standard.

If I had a tiny bit of feedback to provide it would be to print out the errno 
and paths in the connect/bind commands in the DBG commands. I had to bust out 
strace to get that info. Small problem, but it could have saved me a few hours 
and some mailing list messages.

Thank you for making this nice looking software available for free. Looking 
forward to playing with it some more.

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