Project

General

Profile

Actions

Bug #479

closed

Tracing of a real-time application drops a big amount of events at the end of the trace

Added by Raphaël Beamonte over 11 years ago. Updated over 11 years ago.

Status:
Resolved
Priority:
Low
Assignee:
-
Target version:
-
Start date:
03/22/2013
Due date:
% Done:

0%

Estimated time:

Description

This behavior appears with or without using the read-timer option.
It appeared with the commit 34a91bdb42a2a3b01b687ab5e1ba7638401e6dfc implementing the read-timer for realtime.

Tests and results

npt

The tests were made with npt, which is available on the dorsal's git

Test procedure

  • We have 4 CPUs. We isolate them with cpusets
  • We keep the system on CPU 0.
  • We start a sessiond daemon on CPU 2
  • We isolate a shell session on CPU 1 and then run the following commands as root :
    lttng create lttngrt
    lttng enable-channel u -u --num-subbuf 32 --subbuf-size 1048576
    lttng enable-event -c u -u "npt:loop","npt:start","npt:stop" 
    ./npt --eval-cpu-speed -l10000000
    lttng destroy
    
  • We verify the trace : babeltrace lttngrt-trace > /dev/null

Results

With the commit "34a91bdb42a2a3b01b687ab5e1ba7638401e6dfc" of LTTng-UST, not depending on the commit used for LTTng-tools (just watch the locked-steps), we can observe the same behavior for all tests made, using or not a "read-timer" option in the enable-channel line presented in previous section. This behavior is that the latency during the trace is relatively low, but many events are droped at the end of the trace (the "read-timer" had only an impact on whether or not there were droped events during trace in addition to those at the end, but with a low value of read-timer, this other problem disapeared). In fact, always the same amount of events for the same amount of loops used in the call of npt : 8602021.
For commits previous this one, this behavior does not appear and the trace is complete.

However, this behavior was encountered for the previous commits during the tests when I made a mistake and forgot to isolate the sessiond on the CPU 2. In fact, as I forgot to start the sessiond, it was starting during the call to "lttng create", and then was on the same CPU as npt. In this situation, the amount of droped events was exactly the same.

Actions

Also available in: Atom PDF