<div dir="ltr"><div>Bug filed;</div><a href="https://bugs.lttng.org/issues/860">https://bugs.lttng.org/issues/860</a><br><div class="gmail_extra"><br clear="all"><div><div class="gmail_signature">Anders Wallin</div></div>
<br><div class="gmail_quote">On Fri, Nov 14, 2014 at 8:58 PM, Julien Desfossez <span dir="ltr"><<a href="mailto:jdesfossez@efficios.com" target="_blank">jdesfossez@efficios.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">Indeed, it's a problem, would you mind filling a bug report on<br>
<a href="https://bugs.lttng.org/projects/lttng-tools" target="_blank">https://bugs.lttng.org/projects/lttng-tools</a> so we can keep track of this<br>
issue ?<br>
<br>
Thanks,<br>
<br>
Julien<br>
<div><div class="h5"><br>
On 14-11-13 04:40 PM, Anders Wallin wrote:<br>
> Looks like the patch creates a design bug.<br>
> If you have one channel enabled the max snapshot size will be equal to<br>
> one buffer times the number of channels (seems to be 8??)<br>
> So max AND min size will always be the same and always much smaller then<br>
> the content of the buffers<br>
> The size argument passed to snapshot record is never used (or if it's to<br>
> small it will complain)<br>
><br>
> A Q&D workaround to get "all" data out is to create a 2nd non-used<br>
> channel like this;<br>
><br>
> : ${NO_OF_SUBBUF:=6}<br>
> : ${SUBBUF_SIZE:=4096}<br>
><br>
> SESSION=test<br>
> CHANNEL1=ch1<br>
> CHANNEL2=ch2<br>
><br>
> CH2_SUBBUF_SIZE=$(($SUBBUF_SIZE*$NO_OF_SUBBUF))<br>
> .....<br>
><br>
> $LTTNG create $SESSION --snapshot<br>
> $LTTNG enable-channel -u --subbuf-size $SUBBUF_SIZE --num-subbuf<br>
> $NO_OF_SUBBUF --overwrite $CHANNEL1<br>
> $LTTNG enable-channel -u --subbuf-size $CH2_SUBBUF_SIZE --num-subbuf 2<br>
> --overwrite $CHANNEL2<br>
> $LTTNG enable-event -u -c $CHANNEL1 "*"<br>
> ....<br>
><br>
> Then I found another issue about the content of the traces, but I will<br>
> file this under another topic<br>
><br>
><br>
> Anders Wallin<br>
><br>
> On Thu, Nov 13, 2014 at 6:41 PM, Anders Wallin <<a href="mailto:wallinux@gmail.com">wallinux@gmail.com</a><br>
</div></div><span class="">> <mailto:<a href="mailto:wallinux@gmail.com">wallinux@gmail.com</a>>> wrote:<br>
><br>
>     No, I get the same problem with or w/o setting the size<br>
><br>
>     Anders Wallin<br>
><br>
>     On Thu, Nov 13, 2014 at 5:45 PM, Julien Desfossez<br>
</span><span class="">>     <<a href="mailto:jdesfossez@efficios.com">jdesfossez@efficios.com</a> <mailto:<a href="mailto:jdesfossez@efficios.com">jdesfossez@efficios.com</a>>> wrote:<br>
><br>
>         Ok, so if you don't limit the size of the snapshot (remove the<br>
>         -m 1G) it<br>
>         works as expected ?<br>
><br>
>         Julien<br>
><br>
>         On 14-11-13 10:33 AM, Anders Wallin wrote:<br>
>         > bug is introduced in  68808f4e0bbb3adccff72ff9dab6ec9f3a9e6866<br>
>         ><br>
>         > Regards<br>
>         ><br>
>         > Anders<br>
>         ><br>
>         > Anders Wallin<br>
>         ><br>
>         > On Thu, Nov 13, 2014 at 10:39 AM, Anders Wallin <<a href="mailto:wallinux@gmail.com">wallinux@gmail.com</a> <mailto:<a href="mailto:wallinux@gmail.com">wallinux@gmail.com</a>><br>
</span><span class="">>         > <mailto:<a href="mailto:wallinux@gmail.com">wallinux@gmail.com</a> <mailto:<a href="mailto:wallinux@gmail.com">wallinux@gmail.com</a>>>> wrote:<br>
>         ><br>
>         ><br>
>         ><br>
>         >     Anders Wallin<br>
>         ><br>
>         >     On Thu, Nov 13, 2014 at 8:43 AM, Anders Wallin <<a href="mailto:wallinux@gmail.com">wallinux@gmail.com</a> <mailto:<a href="mailto:wallinux@gmail.com">wallinux@gmail.com</a>><br>
</span><span class="">>         >     <mailto:<a href="mailto:wallinux@gmail.com">wallinux@gmail.com</a> <mailto:<a href="mailto:wallinux@gmail.com">wallinux@gmail.com</a>>>> wrote:<br>
>         ><br>
>         >         On Thu, Nov 13, 2014 at 12:11 AM, Julien Desfossez<br>
>         >         <<a href="mailto:jdesfossez@efficios.com">jdesfossez@efficios.com</a> <mailto:<a href="mailto:jdesfossez@efficios.com">jdesfossez@efficios.com</a>><br>
</span>>         <mailto:<a href="mailto:jdesfossez@efficios.com">jdesfossez@efficios.com</a><br>
<span class="">>         <mailto:<a href="mailto:jdesfossez@efficios.com">jdesfossez@efficios.com</a>>>> wrote:<br>
>         ><br>
>         >             Hi,<br>
>         ><br>
>         >             On 14-11-12 05:30 PM, Jérémie Galarneau wrote:<br>
>         >             > On Wed, Nov 12, 2014 at 7:39 AM, Anders Wallin<br>
>         >             <<a href="mailto:wallinux@gmail.com">wallinux@gmail.com</a> <mailto:<a href="mailto:wallinux@gmail.com">wallinux@gmail.com</a>><br>
</span><div><div class="h5">>         <mailto:<a href="mailto:wallinux@gmail.com">wallinux@gmail.com</a> <mailto:<a href="mailto:wallinux@gmail.com">wallinux@gmail.com</a>>>> wrote:<br>
>         >             >> Hi,<br>
>         >             >><br>
>         >             >> using userspace snapshot mode in 2.5 seems to<br>
>         broken.<br>
>         >             >><br>
>         >             >> I have small stupid application(tracetest)<br>
>         generating<br>
>         >             1000 events<br>
>         >             >><br>
>         >             >> Running the script (the below is simplified<br>
>         version of<br>
>         >             the script)<br>
>         >             >><br>
>         ><br>
>          ----------------------------------------------------------------------------------<br>
>         >             >> #!/bin/bash<br>
>         >             >> LTTNG='lttng -n'<br>
>         >             >> lttng-sessiond --no-kernel &<br>
>         >             ><br>
>         >             > You should use the "-d" flag to launch the<br>
>         sessiond as a<br>
>         >             daemon. Using<br>
>         >             > "&" might cause the "create" command to launch a<br>
>         second<br>
>         >             session daemon<br>
>         >             > since the first one would not have had the time<br>
>         to open<br>
>         >             create its<br>
>         >             > command sockets.<br>
>         >             ><br>
>         >             >><br>
>         >             >> $LTTNG create test --snapshot<br>
>         >             >> $LTTNG enable-channel -u --subbuf-size 64k<br>
>         --num-subbuf<br>
>         >             16 --overwrite ch1<br>
>         >             >> $LTTNG enable-event -u -c ch1 "*"<br>
>         >             >> $LTTNG start<br>
>         >             >> $LTTNG list ch1<br>
>         >             >><br>
>         >             >> mkdir -p snapshot/<br>
>         >             >><br>
>         >             >> for i in $(seq 1 $LOOPS); do<br>
>         >             >>     ./tracetest<br>
>         >             >>     $LTTNG snapshot record -m 1G<br>
>         >             >><br>
>         >             >>     # print no of events and first and last event<br>
>         >             >>     last=$(ls -1drt<br>
>         $HOME/lttng-traces/$SESSION*/* | tail -1)<br>
>         >             >>     babeltrace $last > snapshot/$<a href="http://i.bt" target="_blank">i.bt</a><br>
</div></div>>         <<a href="http://i.bt" target="_blank">http://i.bt</a>> <<a href="http://i.bt" target="_blank">http://i.bt</a>><br>
<div><div class="h5">>         >             >>     cat snapshot/$<a href="http://i.bt" target="_blank">i.bt</a> <<a href="http://i.bt" target="_blank">http://i.bt</a>><br>
>         <<a href="http://i.bt" target="_blank">http://i.bt</a>> | wc -l<br>
>         >             >>     cat snapshot/$<a href="http://i.bt" target="_blank">i.bt</a> <<a href="http://i.bt" target="_blank">http://i.bt</a>><br>
>         <<a href="http://i.bt" target="_blank">http://i.bt</a>> | head -1<br>
>         >             >>     cat snapshot/$<a href="http://i.bt" target="_blank">i.bt</a> <<a href="http://i.bt" target="_blank">http://i.bt</a>><br>
>         <<a href="http://i.bt" target="_blank">http://i.bt</a>> | tail -1<br>
>         >             >> done<br>
>         >             >><br>
>         >             >> $LTTNG stop<br>
>         >             >> $LTTNG destroy $SESSION<br>
>         >             >><br>
>         ><br>
>          ----------------------------------------------------------------------------------<br>
>         >             >><br>
>         >             >> The result of the run looks like this;<br>
>         >             >> ./test.run<br>
>         >             >> Error: consumer err socket second poll error<br>
>         >             >> Error: Health error occurred in<br>
>         thread_manage_consumer<br>
>         >             >> PERROR - 13:36:59.685167 [23772/23781]: bind inet:<br>
>         >             Address already in use<br>
>         >             >> (in lttcomm_bind_inet_sock() at inet.c:109)<br>
>         >             >> Warning: Another session daemon is using this<br>
>         JUL port.<br>
>         >             JUL support will be<br>
>         >             >> deactivated to prevent interfering with the<br>
>         tracing.<br>
>         >             >><br>
>         >             ><br>
>         >             > Is there a reason why you run two session<br>
>         daemons? I'm<br>
>         >             guessing this<br>
>         >             > is related to my "& vs -d" comment above.<br>
>         >             ><br>
>         >             >> lttng (LTTng Trace Control) 2.5.2 - Fumisterie<br>
>         >             >> BabelTrace Trace Viewer and Converter 1.2.4<br>
>         >             >>         linux-vdso.so.1 =>  (0x00007fffba966000)<br>
>         >             >>         liblttng-ctl.so.0 =><br>
>         >             /usr/lib/x86_64-linux-gnu/liblttng-ctl.so.0<br>
>         >             >> (0x00007fbfe4b1d000)<br>
>         >             >>         librt.so.1 =><br>
>         /lib/x86_64-linux-gnu/librt.so.1<br>
>         >             (0x00007fbfe4915000)<br>
>         >             >>         libxml2.so.2 =><br>
>         >             /usr/lib/x86_64-linux-gnu/libxml2.so.2<br>
>         >             >> (0x00007fbfe45ae000)<br>
>         >             >>         libpopt.so.0 =><br>
>         /lib/x86_64-linux-gnu/libpopt.so.0<br>
>         >             >> (0x00007fbfe43a2000)<br>
>         >             >>         libpthread.so.0 =><br>
>         >             /lib/x86_64-linux-gnu/libpthread.so.0<br>
>         >             >> (0x00007fbfe4184000)<br>
>         >             >>         libc.so.6 =><br>
>         /lib/x86_64-linux-gnu/libc.so.6<br>
>         >             (0x00007fbfe3dbd000)<br>
>         >             >>         /lib64/ld-linux-x86-64.so.2<br>
>         (0x00007fbfe4fac000)<br>
>         >             >>         liburcu.so.2 =><br>
>         >             /usr/lib/x86_64-linux-gnu/liburcu.so.2<br>
>         >             >> (0x00007fbfe3bb6000)<br>
>         >             >>         libdl.so.2 =><br>
>         /lib/x86_64-linux-gnu/libdl.so.2<br>
>         >             (0x00007fbfe39b2000)<br>
>         >             >>         libz.so.1 =><br>
>         /lib/x86_64-linux-gnu/libz.so.1<br>
>         >             (0x00007fbfe3798000)<br>
>         >             >>         liblzma.so.5 =><br>
>         /lib/x86_64-linux-gnu/liblzma.so.5<br>
>         >             >> (0x00007fbfe3576000)<br>
>         >             >>         libm.so.6 =><br>
>         /lib/x86_64-linux-gnu/libm.so.6<br>
>         >             (0x00007fbfe3270000)<br>
>         >             >><br>
>         >             >> Session test created.<br>
>         >             >> Default snapshot output set to:<br>
>         >             >> /home/awallin/lttng-traces/test-20141112-133700<br>
>         >             >> Snapshot mode set. Every channel enabled for<br>
>         that session<br>
>         >             will be set in<br>
>         >             >> overwrite mode and mmap output.<br>
>         >             >> UST channel ch1 enabled for session test<br>
>         >             >> UST event * created in channel ch1<br>
>         >             >> Tracing started for session test<br>
>         >             >> Tracing session test: [active snapshot]<br>
>         >             >>     Trace path:<br>
>         >             >>     Live timer interval (usec): 4294967295<br>
>         >             >><br>
>         >             >> === Domain: UST global ===<br>
>         >             >><br>
>         >             >> Channels:<br>
>         >             >> -------------<br>
>         >             >> - ch1: [enabled]<br>
>         >             >><br>
>         >             >>     Attributes:<br>
>         >             >>       overwrite mode: 1<br>
>         >             >>       subbufers size: 4096<br>
>         >             >>       number of subbufers: 16<br>
>         >             >>       switch timer interval: 0<br>
>         >             >>       read timer interval: 0<br>
>         >             >>       trace file count: 0<br>
>         >             >>       trace file size (bytes): 0<br>
>         >             >>       output: mmap()<br>
>         >             >><br>
>         >             >>     Events:<br>
>         >             >>       * (type: tracepoint) [enabled]<br>
>         >             >><br>
>         >             >> Snapshot recorded successfully for session test<br>
>         >             >> 84<br>
>         >             >> [13:37:00.852615950] (+?.?????????)<br>
>         arn-awallin-mint-l3<br>
>         >             >> ust_baddr_statedump:soinfo: { cpu_id = 4 }, {<br>
>         baddr =<br>
>         >             0x7FFFC6BC7000, sopath<br>
>         >             >> = "[vdso]", size = 0, mtime = -1 }<br>
>         >             >> [13:37:00.853798949] (+0.000000805)<br>
>         arn-awallin-mint-l3<br>
>         >             tracetest:first_tp:<br>
>         >             >> { cpu_id = 6 }, { my_string_field = "test",<br>
>         >             my_integer_field = 999 }<br>
>         >             >> Snapshot recorded successfully for session test<br>
>         >             >> 157<br>
>         >             >> [13:37:00.853735195] (+?.?????????)<br>
>         arn-awallin-mint-l3<br>
>         >             tracetest:first_tp:<br>
>         >             >> { cpu_id = 6 }, { my_string_field = "test",<br>
>         >             my_integer_field = 927 }<br>
>         >             >> [13:37:00.894839116] (+0.000000299)<br>
>         arn-awallin-mint-l3<br>
>         >             tracetest:first_tp:<br>
>         >             >> { cpu_id = 5 }, { my_string_field = "test",<br>
>         >             my_integer_field = 999 }<br>
>         >             >> Snapshot recorded successfully for session test<br>
>         >             >> 168<br>
>         >             >> [13:37:00.853735195] (+?.?????????)<br>
>         arn-awallin-mint-l3<br>
>         >             tracetest:first_tp:<br>
>         >             >> { cpu_id = 6 }, { my_string_field = "test",<br>
>         >             my_integer_field = 927 }<br>
>         >             >> [13:37:00.929447330] (+0.000000305)<br>
>         arn-awallin-mint-l3<br>
>         >             tracetest:first_tp:<br>
>         >             >> { cpu_id = 5 }, { my_string_field = "test",<br>
>         >             my_integer_field = 999 }<br>
>         >             >> Snapshot recorded successfully for session test<br>
>         ><br>
>         >             Something is wrong from here:<br>
>         >             >> 168<br>
>         >             >> [13:37:00.894411117] (+?.?????????)<br>
>         arn-awallin-mint-l3<br>
>         >             >> ust_baddr_statedump:soinfo: { cpu_id = 4 }, {<br>
>         baddr = 0x7FFF6BF81000, sopath<br>
>         >             >> = "[vdso]", size = 0, mtime = -1 }<br>
>         >             >> [13:37:00.972035546] (+0.000000597)<br>
>         arn-awallin-mint-l3 tracetest:first_tp:<br>
>         >             >> { cpu_id = 6 }, { my_string_field = "test",<br>
>         my_integer_field = 999 }<br>
>         >             >> Snapshot recorded successfully for session test<br>
>         >             >> 168<br>
>         >             >> [13:37:00.894411117] (+?.?????????)<br>
>         arn-awallin-mint-l3<br>
>         >             >> ust_baddr_statedump:soinfo: { cpu_id = 4 }, {<br>
>         baddr = 0x7FFF6BF81000, sopath<br>
>         >             >> = "[vdso]", size = 0, mtime = -1 }<br>
>         >             >> [13:37:01.014060940 <tel:014060940><br>
</div></div>>         <tel:<a href="tel:014060940" value="+4614060940">014060940</a> <tel:<a href="tel:014060940" value="+4614060940">014060940</a>>>] (+0.000000341)<br>
<span class="">>         >             arn-awallin-mint-l3 tracetest:first_tp:<br>
>         >             >> { cpu_id = 7 }, { my_string_field = "test", my_integer_field = 999 }<br>
>         >             >> Snapshot recorded successfully for session test<br>
>         >             >> 168<br>
>         >             >> [13:37:00.894411117] (+?.?????????) arn-awallin-mint-l3<br>
>         >             >> ust_baddr_statedump:soinfo: { cpu_id = 4 }, { baddr = 0x7FFF6BF81000, sopath<br>
>         >             >> = "[vdso]", size = 0, mtime = -1 }<br>
>         >             >> [13:37:01.052555877 <tel:052555877><br>
</span>>         <tel:<a href="tel:052555877" value="+4652555877">052555877</a> <tel:<a href="tel:052555877" value="+4652555877">052555877</a>>>] (+0.000000872)<br>
<span class="">>         >             arn-awallin-mint-l3 tracetest:first_tp:<br>
>         >             >> { cpu_id = 6 }, { my_string_field = "test", my_integer_field = 999 }<br>
>         >             ... to here.<br>
>         ><br>
>         >             The beginning timestamp is the same, the number of events is<br>
>         >             the same,<br>
>         >             but the end timestamp moves. We see also this pattern below.<br>
>         >             I would be really interested to see the whole snapshots when<br>
>         >             it happens.<br>
>         >             It seems like we are not be overwriting the beginning of the<br>
>         >             ring buffer<br>
>         >             in some conditions. Could you send us your tracetest program<br>
>         >             and the<br>
>         >             script so we can try to reproduce the problem ?<br>
>         ><br>
>         ><br>
>         >         I will append it including a run with debug turned on and all<br>
>         >         the snapshot files created<br>
>         ><br>
>         ><br>
>         ><br>
>         >             >> Snapshot recorded successfully for session test<br>
>         >             >> 168<br>
>         >             >> [13:37:01.<a href="tel:014035993" value="+4614035993">014035993</a> <tel:<a href="tel:014035993" value="+4614035993">014035993</a>><br>
</span>>         <tel:<a href="tel:014035993" value="+4614035993">014035993</a> <tel:<a href="tel:014035993" value="+4614035993">014035993</a>>>] (+?.?????????)<br>
<span class="">>         >             arn-awallin-mint-l3 tracetest:first_tp:<br>
>         >             >> { cpu_id = 7 }, { my_string_field = "test",<br>
>         >             my_integer_field = 927 }<br>
>         >             >> [13:37:01.098620808] (+0.000001404) arn-awallin-mint-l3<br>
>         >             tracetest:first_tp:<br>
>         >             >> { cpu_id = 4 }, { my_string_field = "test",<br>
>         >             my_integer_field = 999 }<br>
>         >             >> Snapshot recorded successfully for session test<br>
>         >             >> 168<br>
>         >             >> [13:37:01.097087388 <tel:097087388><br>
</span>>         <tel:<a href="tel:097087388" value="+4697087388">097087388</a> <tel:<a href="tel:097087388" value="+4697087388">097087388</a>>>] (+?.?????????)<br>
<span class="">>         >             arn-awallin-mint-l3<br>
>         >             >> ust_baddr_statedump:soinfo: { cpu_id = 6 }, { baddr =<br>
>         >             0x7FFF4BFFE000, sopath<br>
>         >             >> = "[vdso]", size = 0, mtime = -1 }<br>
>         >             >> [13:37:01.129839830] (+0.000000533) arn-awallin-mint-l3<br>
>         >             tracetest:first_tp:<br>
>         >             >> { cpu_id = 7 }, { my_string_field = "test",<br>
>         >             my_integer_field = 999 }<br>
>         >             >> Snapshot recorded successfully for session test<br>
>         >             >> 168<br>
>         >             >> [13:37:01.097087388 <tel:097087388><br>
</span>>         <tel:<a href="tel:097087388" value="+4697087388">097087388</a> <tel:<a href="tel:097087388" value="+4697087388">097087388</a>>>] (+?.?????????)<br>
<span class="">>         >             arn-awallin-mint-l3<br>
>         >             >> ust_baddr_statedump:soinfo: { cpu_id = 6 }, { baddr =<br>
>         >             0x7FFF4BFFE000, sopath<br>
>         >             >> = "[vdso]", size = 0, mtime = -1 }<br>
>         >             >> [13:37:01.129839830] (+0.000000533) arn-awallin-mint-l3<br>
>         >             tracetest:first_tp:<br>
>         >             >> { cpu_id = 7 }, { my_string_field = "test",<br>
>         >             my_integer_field = 999 }<br>
>         >             >> Snapshot recorded successfully for session test<br>
>         >             >> 168<br>
>         >             >> [13:37:01.097087388 <tel:097087388><br>
</span>>         <tel:097087388 <tel:097087388>>] (+?.?????????)<br>
<div><div class="h5">>         >             arn-awallin-mint-l3<br>
>         >             >> ust_baddr_statedump:soinfo: { cpu_id = 6 }, {<br>
>         baddr =<br>
>         >             0x7FFF4BFFE000, sopath<br>
>         >             >> = "[vdso]", size = 0, mtime = -1 }<br>
>         >             >> [13:37:01.172829105] (+0.000000575)<br>
>         arn-awallin-mint-l3<br>
>         >             tracetest:first_tp:<br>
>         >             >> { cpu_id = 5 }, { my_string_field = "test",<br>
>         >             my_integer_field = 999 }<br>
>         >             >> Snapshot recorded successfully for session test<br>
>         >             >> 168<br>
>         >             >> [13:37:01.172021557] (+?.?????????)<br>
>         arn-awallin-mint-l3<br>
>         >             >> ust_baddr_statedump:soinfo: { cpu_id = 7 }, {<br>
>         baddr =<br>
>         >             0x7FFF653FE000, sopath<br>
>         >             >> = "[vdso]", size = 0, mtime = -1 }<br>
>         >             >> [13:37:01.220074165] (+0.000000553)<br>
>         arn-awallin-mint-l3<br>
>         >             tracetest:first_tp:<br>
>         >             >> { cpu_id = 6 }, { my_string_field = "test",<br>
>         >             my_integer_field = 999 }<br>
>         >             >> Waiting for data availability<br>
>         >             >> Tracing stopped for session test<br>
>         >             >> Session test destroyed<br>
>         >             >><br>
>         >             >> the result from the run on older versions of lttng<br>
>         >             creates bigger and bigger<br>
>         >             >> event traces until reaching max size.<br>
>         >             We see this pattern here and the max size seems to<br>
>         be 168<br>
>         >             events, was it<br>
>         >             similar in your previous tests ?<br>
>         ><br>
>         >         If I'm running the same test on 2.4 or 2.3 the max<br>
>         number of<br>
>         >         events is much bigger, like ~10000<br>
>         >         (I don't have the exact number right now, I will<br>
>         rebuild and run<br>
>         >         the test again and get back<br>
>         >         with traces from that run)<br>
>         ><br>
>         >     For 2.4.2 the log looks like this:<br>
>         >     ./test.run ./tracetest<br>
>         ><br>
>         >     lttng (LTTng Trace Control) 2.4.2 - Époque Opaque<br>
>         >     BabelTrace Trace Viewer and Converter 1.2.1<br>
>         >     linux-vdso.so.1 =>  (0x00007fff775fe000)<br>
>         >     liblttng-ctl.so.0 => /usr/local/lib/liblttng-ctl.so.0<br>
>         >     (0x00002b2b016e4000)<br>
>         >     libpopt.so.0 => /lib/x86_64-linux-gnu/libpopt.so.0<br>
>         (0x00002b2b0190f000)<br>
>         >     libpthread.so.0 => /lib/x86_64-linux-gnu/libpthread.so.0<br>
>         >     (0x00002b2b01b1b000)<br>
>         >     libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6<br>
>         (0x00002b2b01d39000)<br>
>         >     librt.so.1 => /lib/x86_64-linux-gnu/librt.so.1<br>
>         (0x00002b2b020ff000)<br>
>         >     liburcu.so.3 => /usr/local/lib/liburcu.so.3<br>
>         (0x00002b2b02307000)<br>
>         >     /lib64/ld-linux-x86-64.so.2 (0x00002b2b014bf000)<br>
>         ><br>
>         >     Session test created.<br>
>         >     Default snapshot output set to:<br>
>         //lttng-traces/test-20141113-093611<br>
>         >     Snapshot mode set. Every channel enabled for that session<br>
>         will be<br>
>         >     set in overwrite mode and mmap output.<br>
>         >     UST channel ch1 enabled for session test<br>
>         >     UST event * created in channel ch1<br>
>         >     Tracing started for session test<br>
>         >     Tracing session test: [active snapshot]<br>
>         >         Trace path:<br>
>         ><br>
>         >     === Domain: UST global ===<br>
>         ><br>
>         >     Buffer type: per UID<br>
>         ><br>
>         >     Channels:<br>
>         >     -------------<br>
>         >     - ch1: [enabled]<br>
>         ><br>
>         >         Attributes:<br>
>         >           overwrite mode: 1<br>
>         >           subbufers size: 4096<br>
>         >           number of subbufers: 16<br>
>         >           switch timer interval: 0<br>
>         >           read timer interval: 0<br>
>         >           output: mmap()<br>
>         ><br>
>         >         Events:<br>
>         >           * (type: tracepoint) [enabled]<br>
>         ><br>
>         >     Snapshot recorded successfully for session test<br>
>         >     1000<br>
>         >     [09:36:11.985319272] (+?.?????????) 07f8cf84a38f<br>
>         tracetest:first_tp:<br>
>         >     { cpu_id = 4 }, { my_string_field = "test",<br>
>         my_integer_field = 0 }<br>
>         >     [09:36:11.985857254] (+0.000000501) 07f8cf84a38f<br>
>         tracetest:first_tp:<br>
>         >     { cpu_id = 4 }, { my_string_field = "test",<br>
>         my_integer_field = 999 }<br>
>         >     Snapshot recorded successfully for session test<br>
>         >     2000<br>
>         >     [09:36:11.985319272] (+?.?????????) 07f8cf84a38f<br>
>         tracetest:first_tp:<br>
>         >     { cpu_id = 4 }, { my_string_field = "test",<br>
>         my_integer_field = 0 }<br>
</div></div>>         >     [09:36:12.033066130 <tel:033066130> <tel:033066130<br>
<span class="">>         <tel:033066130>>] (+0.000001663) 07f8cf84a38f<br>
>         >     tracetest:first_tp: { cpu_id = 5 }, { my_string_field = "test",<br>
>         >     my_integer_field = 999 }<br>
>         >     Snapshot recorded successfully for session test<br>
>         >     3000<br>
>         >     [09:36:11.985319272] (+?.?????????) 07f8cf84a38f tracetest:first_tp:<br>
>         >     { cpu_id = 4 }, { my_string_field = "test", my_integer_field = 0 }<br>
</span>>         >     [09:36:12.086888121 <tel:086888121> <tel:086888121<br>
<div class="HOEnZb"><div class="h5">>         <tel:086888121>>] (+0.000001273) 07f8cf84a38f<br>
>         >     tracetest:first_tp: { cpu_id = 5 }, { my_string_field =<br>
>         "test",<br>
>         >     my_integer_field = 999 }<br>
>         >     Snapshot recorded successfully for session test<br>
>         >     4000<br>
>         >     [09:36:11.985319272] (+?.?????????) 07f8cf84a38f<br>
>         tracetest:first_tp:<br>
>         >     { cpu_id = 4 }, { my_string_field = "test",<br>
>         my_integer_field = 0 }<br>
>         >     [09:36:12.147378251] (+0.000001257) 07f8cf84a38f<br>
>         tracetest:first_tp:<br>
>         >     { cpu_id = 4 }, { my_string_field = "test",<br>
>         my_integer_field = 999 }<br>
>         >     Snapshot recorded successfully for session test<br>
>         >     5000<br>
>         >     [09:36:11.985319272] (+?.?????????) 07f8cf84a38f<br>
>         tracetest:first_tp:<br>
>         >     { cpu_id = 4 }, { my_string_field = "test",<br>
>         my_integer_field = 0 }<br>
>         >     [09:36:12.225584696] (+0.000000528) 07f8cf84a38f<br>
>         tracetest:first_tp:<br>
>         >     { cpu_id = 4 }, { my_string_field = "test",<br>
>         my_integer_field = 999 }<br>
>         >     Snapshot recorded successfully for session test<br>
>         >     6000<br>
>         >     [09:36:11.985319272] (+?.?????????) 07f8cf84a38f<br>
>         tracetest:first_tp:<br>
>         >     { cpu_id = 4 }, { my_string_field = "test",<br>
>         my_integer_field = 0 }<br>
>         >     [09:36:12.288311172] (+0.000000571) 07f8cf84a38f<br>
>         tracetest:first_tp:<br>
>         >     { cpu_id = 7 }, { my_string_field = "test",<br>
>         my_integer_field = 999 }<br>
>         >     Snapshot recorded successfully for session test<br>
>         >     7000<br>
>         >     [09:36:11.985319272] (+?.?????????) 07f8cf84a38f<br>
>         tracetest:first_tp:<br>
>         >     { cpu_id = 4 }, { my_string_field = "test",<br>
>         my_integer_field = 0 }<br>
>         >     [09:36:12.375789307] (+0.000001238) 07f8cf84a38f<br>
>         tracetest:first_tp:<br>
>         >     { cpu_id = 4 }, { my_string_field = "test",<br>
>         my_integer_field = 999 }<br>
>         >     Snapshot recorded successfully for session test<br>
>         >     7000<br>
>         >     [09:36:12.032314084] (+?.?????????) 07f8cf84a38f<br>
>         tracetest:first_tp:<br>
>         >     { cpu_id = 5 }, { my_string_field = "test",<br>
>         my_integer_field = 0 }<br>
>         >     [09:36:12.460756779] (+0.000001248) 07f8cf84a38f<br>
>         tracetest:first_tp:<br>
>         >     { cpu_id = 4 }, { my_string_field = "test",<br>
>         my_integer_field = 999 }<br>
>         >     Snapshot recorded successfully for session test<br>
>         >     8000<br>
>         >     [09:36:12.032314084] (+?.?????????) 07f8cf84a38f<br>
>         tracetest:first_tp:<br>
>         >     { cpu_id = 5 }, { my_string_field = "test",<br>
>         my_integer_field = 0 }<br>
>         >     [09:36:12.540464090] (+0.000001292) 07f8cf84a38f<br>
>         tracetest:first_tp:<br>
>         >     { cpu_id = 7 }, { my_string_field = "test",<br>
>         my_integer_field = 999 }<br>
>         >     Snapshot recorded successfully for session test<br>
>         >     9000<br>
>         >     [09:36:12.032314084] (+?.?????????) 07f8cf84a38f<br>
>         tracetest:first_tp:<br>
>         >     { cpu_id = 5 }, { my_string_field = "test",<br>
>         my_integer_field = 0 }<br>
>         >     [09:36:12.621992931] (+0.000001298) 07f8cf84a38f<br>
>         tracetest:first_tp:<br>
>         >     { cpu_id = 5 }, { my_string_field = "test",<br>
>         my_integer_field = 999 }<br>
>         >     Waiting for data availability<br>
>         >     Tracing stopped for session test<br>
>         >     Session test destroyed<br>
>         ><br>
>         ><br>
>         ><br>
>         >             ><br>
>         >             > Unless I'm mistaken, the behavior of the<br>
>         snapshot mode has changed<br>
>         >             > between 2.4 and 2.5.<br>
>         >             ><br>
>         >             > In the 2.4 series, consecutive snapshots could<br>
>         overlap; that is,<br>
>         >             > events could be present in multiple snapshots.<br>
>         As of 2.5, an event is<br>
>         >             > guaranteed to only appear in one snapshot as the<br>
>         events are considered<br>
>         >             > as having been "consumed" at that point.<br>
>         ><br>
>         >             Hum, no the behavior is still the same, consecutive<br>
>         >             snapshots can overlap.<br>
>         ><br>
>         >             Could you tell us on which architecture you are<br>
>         experiencing<br>
>         >             the problem<br>
>         >             and the number of CPUs ?<br>
>         ><br>
>         >         The traces appended is from my laptop running Ubuntu<br>
>         14.04 with<br>
>         >         "8" cpu's<br>
>         >         model name      : Intel(R) Core(TM) i7-2760QM CPU @<br>
>         2.40GHz<br>
>         >         I have also run this on ARM with 16 cores and a powerpc<br>
>         ><br>
>         ><br>
>         >             Thanks,<br>
>         ><br>
>         >             Julien<br>
>         ><br>
>         ><br>
>         ><br>
>         ><br>
><br>
><br>
><br>
</div></div></blockquote></div><br></div></div>