[lttng-dev] Snapshot gives no events after calling it more then the number sub-buffers in the channel

[Mathieu Desnoyers]

----- On Dec 7, 2016, at 9:27 AM, Anders Wallin <wallinux at gmail.com> wrote: 

> Hi,
> Taking a number of snapshots always showed the events in the buffer, before the
> commit de3fb857f034c208c135a10a3cdec2dfe43fbda6

> Fix: ust-consumer: flush empty packets on snapshot channel
> Snapshot operation on a non-stopped stream should use a "final" flush to
> ensure empty packets are flushed, so we gather timestamps at the moment
> where the snapshot is taken. This is important for streams that have a
> low amount of activity, which might be on an empty packet when the
> snapshot is triggered.

> After this the number of snapshots that can be taken and getting events is equal
> to number of sub-buffers!?
> I think this i BUG!

Hi, 

This has been done on purpose. By moving one packet forward even if there is no data 
in the current packet, we are able to save the end timestamp corresponding to the moment the 
snapshot is taken, which gives us information about the proper time-range to consider for each 
stream. 

This is needed for the babeltrace stream intersection feature to work properly on 
snapshots in cases where some streams have low even throughput. 

Can you describe your use-cases that rely on the prior behavior ? 

Thanks, 

Mathieu 

> The following test script shows the problem!
> -----------------------------------------------------------------
> #!/bin/sh

> TRACEAPP="/usr/lib/lttng-tools/ptest/tests/utils/testapp/gen-ust-events/gen-ust-events
> 1"
> TRACEPATH=$HOME/lttng-snapshots
> SESSION=tracetest
> CHANNEL=tracechannel

> # cleanup
> lttng destroy $SESSION
> rm -rf $TRACEPATH
> sleep 1

> lttng create $SESSION --snapshot -U file://$TRACEPATH
> lttng enable-channel $CHANNEL -u --subbuf-size 4k --num-subbuf 2
> lttng enable-event -a -u -c $CHANNEL -s $SESSION
> lttng start $SESSION
> lttng --version
> #lttng list $SESSION

> $TRACEAPP
> sleep 1

> for i in $(seq 1 5); do
> lttng snapshot record --session $SESSION --name $i-something
> sleep 1
> echo "------------------------------------"
> echo " $i print events"
> babeltrace $TRACEPATH/$i-something* | head -1
> done
> ------------------------------------------------------------------------

> BEFOR the patch the output is like this (I have removed some lines to make it
> easier to read);
> --------------------------------------------------------------------------------------------------------------------------
> Session tracetest created.
> Default snapshot output set to: file:///root/lttng-snapshots
> Snapshot mode set. Every channel enabled for that session will be set in
> overwrite mode and mmap output.
> UST channel tracechannel enabled for session tracetest
> All UST events are enabled in channel tracechannel
> Tracing started for session tracetest
> lttng (LTTng Trace Control) 2.7.2

> --- create some user events ---
> Snapshot recorded successfully for session tracetest
> ------------------------------------
> 1 print events
> [15:02:11.886716015] (+?.?????????) axxiaarm lttng_ust_statedump:start: { cpu_id
> = 9 }, { }
> ------------------------------------
> Snapshot recorded successfully for session tracetest
> 2 print events
> [15:02:11.886716015] (+?.?????????) axxiaarm lttng_ust_statedump:start: { cpu_id
> = 9 }, { }
> ------------------------------------
> Snapshot recorded successfully for session tracetest
> 3 print events
> [15:02:11.886716015] (+?.?????????) axxiaarm lttng_ust_statedump:start: { cpu_id
> = 9 }, { }
> ------------------------------------
> Snapshot recorded successfully for session tracetest
> 4 print events
> [15:02:11.886716015] (+?.?????????) axxiaarm lttng_ust_statedump:start: { cpu_id
> = 9 }, { }
> ------------------------------------
> Snapshot recorded successfully for session tracetest
> 5 print events
> [15:02:11.886716015] (+?.?????????) axxiaarm lttng_ust_statedump:start: { cpu_id
> = 9 }, { }

> AFTER the patch the output is like this (I have removed some lines to make it
> easier to read);
> --------------------------------------------------------------------------------------------------------------------------
> Session tracetest created.
> Default snapshot output set to: file:///root/lttng-snapshots
> Snapshot mode set. Every channel enabled for that session will be set in
> overwrite mode and mmap output.
> UST channel tracechannel enabled for session tracetest
> All UST events are enabled in channel tracechannel
> Tracing started for session tracetest
> lttng (LTTng Trace Control) 2.7.5

> --- create some user events ---
> Snapshot recorded successfully for session tracetest
> ------------------------------------
> 1 print events
> [15:02:11.886716015] (+?.?????????) axxiaarm lttng_ust_statedump:start: { cpu_id
> = 9 }, { }
> ------------------------------------
> Snapshot recorded successfully for session tracetest
> 2 print events
> [15:02:11.886716015] (+?.?????????) axxiaarm lttng_ust_statedump:start: { cpu_id
> = 9 }, { }
> ------------------------------------
> Snapshot recorded successfully for session tracetest
> 3 print events
> ------------------------------------
> Snapshot recorded successfully for session tracetest
> 4 print events
> ------------------------------------
> Snapshot recorded successfully for session tracetest
> 5 print events

> Tested on 2.7.5 and 2.8.2 with the same result

> Regards
> Anders Wallin

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

-- 
Mathieu Desnoyers 
EfficiOS Inc. 
http://www.efficios.com 
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.lttng.org/pipermail/lttng-dev/attachments/20161208/93bc78b5/attachment.html>