<div dir="ltr">Hi,<div><br></div><div>using userspace snapshot mode in 2.5 seems to broken.</div><div><br></div><div>I have small stupid application(tracetest) generating 1000 events </div><div><br></div><div>Running the script (the below is simplified version of the script)</div><div><div><div>----------------------------------------------------------------------------------</div></div><div>#!/bin/bash<br></div><div>LTTNG='lttng -n'</div><div>lttng-sessiond --no-kernel &<br></div><div><br></div><div>$LTTNG create test --snapshot<br></div><div>$LTTNG enable-channel -u --subbuf-size 64k --num-subbuf 16 --overwrite ch1</div><div>$LTTNG enable-event -u -c ch1 "*"</div><div>$LTTNG start</div><div>$LTTNG list ch1</div><div><br></div><div>mkdir -p snapshot/</div><div><br></div><div>for i in $(seq 1 $LOOPS); do</div><div> ./tracetest<br></div><div> $LTTNG snapshot record -m 1G<br></div><div><br></div><div> # print no of events and first and last event</div><div> last=$(ls -1drt $HOME/lttng-traces/$SESSION*/* | tail -1)</div><div> babeltrace $last > snapshot/$<a href="http://i.bt">i.bt</a></div><div> cat snapshot/$<a href="http://i.bt">i.bt</a> | wc -l</div><div> cat snapshot/$<a href="http://i.bt">i.bt</a> | head -1</div><div> cat snapshot/$<a href="http://i.bt">i.bt</a> | tail -1</div><div>done</div><div><br></div><div>$LTTNG stop</div><div>$LTTNG destroy $SESSION</div></div><div>----------------------------------------------------------------------------------</div><div><br></div><div>The result of the run looks like this;</div><div><div>./test.run </div><div>Error: consumer err socket second poll error</div><div>Error: Health error occurred in thread_manage_consumer</div><div>PERROR - 13:36:59.685167 [23772/23781]: bind inet: Address already in use (in lttcomm_bind_inet_sock() at inet.c:109)</div><div>Warning: Another session daemon is using this JUL port. JUL support will be deactivated to prevent interfering with the tracing.</div><div><br></div><div>lttng (LTTng Trace Control) 2.5.2 - Fumisterie</div><div>BabelTrace Trace Viewer and Converter 1.2.4</div><div> linux-vdso.so.1 => (0x00007fffba966000)</div><div> liblttng-ctl.so.0 => /usr/lib/x86_64-linux-gnu/liblttng-ctl.so.0 (0x00007fbfe4b1d000)</div><div> librt.so.1 => /lib/x86_64-linux-gnu/librt.so.1 (0x00007fbfe4915000)</div><div> libxml2.so.2 => /usr/lib/x86_64-linux-gnu/libxml2.so.2 (0x00007fbfe45ae000)</div><div> libpopt.so.0 => /lib/x86_64-linux-gnu/libpopt.so.0 (0x00007fbfe43a2000)</div><div> libpthread.so.0 => /lib/x86_64-linux-gnu/libpthread.so.0 (0x00007fbfe4184000)</div><div> libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007fbfe3dbd000)</div><div> /lib64/ld-linux-x86-64.so.2 (0x00007fbfe4fac000)</div><div> liburcu.so.2 => /usr/lib/x86_64-linux-gnu/liburcu.so.2 (0x00007fbfe3bb6000)</div><div> libdl.so.2 => /lib/x86_64-linux-gnu/libdl.so.2 (0x00007fbfe39b2000)</div><div> libz.so.1 => /lib/x86_64-linux-gnu/libz.so.1 (0x00007fbfe3798000)</div><div> liblzma.so.5 => /lib/x86_64-linux-gnu/liblzma.so.5 (0x00007fbfe3576000)</div><div> libm.so.6 => /lib/x86_64-linux-gnu/libm.so.6 (0x00007fbfe3270000)</div><div><br></div><div>Session test created.</div><div>Default snapshot output set to: /home/awallin/lttng-traces/test-20141112-133700</div><div>Snapshot mode set. Every channel enabled for that session will be set in overwrite mode and mmap output.</div><div>UST channel ch1 enabled for session test</div><div>UST event * created in channel ch1</div><div>Tracing started for session test</div><div>Tracing session test: [active snapshot]</div><div> Trace path: </div><div> Live timer interval (usec): 4294967295</div><div><br></div><div>=== Domain: UST global ===</div></div><div><br></div><div><div>Channels:</div><div>-------------</div><div>- ch1: [enabled]</div><div><br></div><div> Attributes:</div><div> overwrite mode: 1</div><div> subbufers size: 4096</div><div> number of subbufers: 16</div><div> switch timer interval: 0</div><div> read timer interval: 0</div><div> trace file count: 0</div><div> trace file size (bytes): 0</div><div> output: mmap()</div><div><br></div><div> Events:</div><div> * (type: tracepoint) [enabled]</div><div><br></div><div>Snapshot recorded successfully for session test</div><div>84</div><div>[13:37:00.852615950] (+?.?????????) arn-awallin-mint-l3 ust_baddr_statedump:soinfo: { cpu_id = 4 }, { baddr = 0x7FFFC6BC7000, sopath = "[vdso]", size = 0, mtime = -1 }</div><div>[13:37:00.853798949] (+0.000000805) arn-awallin-mint-l3 tracetest:first_tp: { cpu_id = 6 }, { my_string_field = "test", my_integer_field = 999 }</div><div>Snapshot recorded successfully for session test</div><div>157</div><div>[13:37:00.853735195] (+?.?????????) arn-awallin-mint-l3 tracetest:first_tp: { cpu_id = 6 }, { my_string_field = "test", my_integer_field = 927 }</div><div>[13:37:00.894839116] (+0.000000299) arn-awallin-mint-l3 tracetest:first_tp: { cpu_id = 5 }, { my_string_field = "test", my_integer_field = 999 }</div><div>Snapshot recorded successfully for session test</div><div>168</div><div>[13:37:00.853735195] (+?.?????????) arn-awallin-mint-l3 tracetest:first_tp: { cpu_id = 6 }, { my_string_field = "test", my_integer_field = 927 }</div><div>[13:37:00.929447330] (+0.000000305) arn-awallin-mint-l3 tracetest:first_tp: { cpu_id = 5 }, { my_string_field = "test", my_integer_field = 999 }</div><div>Snapshot recorded successfully for session test</div><div>168</div><div>[13:37:00.894411117] (+?.?????????) arn-awallin-mint-l3 ust_baddr_statedump:soinfo: { cpu_id = 4 }, { baddr = 0x7FFF6BF81000, sopath = "[vdso]", size = 0, mtime = -1 }</div><div>[13:37:00.972035546] (+0.000000597) arn-awallin-mint-l3 tracetest:first_tp: { cpu_id = 6 }, { my_string_field = "test", my_integer_field = 999 }</div><div>Snapshot recorded successfully for session test</div><div>168</div><div>[13:37:00.894411117] (+?.?????????) arn-awallin-mint-l3 ust_baddr_statedump:soinfo: { cpu_id = 4 }, { baddr = 0x7FFF6BF81000, sopath = "[vdso]", size = 0, mtime = -1 }</div><div>[13:37:01.014060940] (+0.000000341) arn-awallin-mint-l3 tracetest:first_tp: { cpu_id = 7 }, { my_string_field = "test", my_integer_field = 999 }</div><div>Snapshot recorded successfully for session test</div><div>168</div><div>[13:37:00.894411117] (+?.?????????) arn-awallin-mint-l3 ust_baddr_statedump:soinfo: { cpu_id = 4 }, { baddr = 0x7FFF6BF81000, sopath = "[vdso]", size = 0, mtime = -1 }</div><div>[13:37:01.052555877] (+0.000000872) arn-awallin-mint-l3 tracetest:first_tp: { cpu_id = 6 }, { my_string_field = "test", my_integer_field = 999 }</div><div>Snapshot recorded successfully for session test</div><div>168</div><div>[13:37:01.014035993] (+?.?????????) arn-awallin-mint-l3 tracetest:first_tp: { cpu_id = 7 }, { my_string_field = "test", my_integer_field = 927 }</div><div>[13:37:01.098620808] (+0.000001404) arn-awallin-mint-l3 tracetest:first_tp: { cpu_id = 4 }, { my_string_field = "test", my_integer_field = 999 }</div><div>Snapshot recorded successfully for session test</div><div>168</div><div>[13:37:01.097087388] (+?.?????????) arn-awallin-mint-l3 ust_baddr_statedump:soinfo: { cpu_id = 6 }, { baddr = 0x7FFF4BFFE000, sopath = "[vdso]", size = 0, mtime = -1 }</div><div>[13:37:01.129839830] (+0.000000533) arn-awallin-mint-l3 tracetest:first_tp: { cpu_id = 7 }, { my_string_field = "test", my_integer_field = 999 }</div><div>Snapshot recorded successfully for session test</div><div><div>168</div><div>[13:37:01.097087388] (+?.?????????) arn-awallin-mint-l3 ust_baddr_statedump:soinfo: { cpu_id = 6 }, { baddr = 0x7FFF4BFFE000, sopath = "[vdso]", size = 0, mtime = -1 }</div><div>[13:37:01.129839830] (+0.000000533) arn-awallin-mint-l3 tracetest:first_tp: { cpu_id = 7 }, { my_string_field = "test", my_integer_field = 999 }</div><div>Snapshot recorded successfully for session test</div><div>168</div><div>[13:37:01.097087388] (+?.?????????) arn-awallin-mint-l3 ust_baddr_statedump:soinfo: { cpu_id = 6 }, { baddr = 0x7FFF4BFFE000, sopath = "[vdso]", size = 0, mtime = -1 }</div><div>[13:37:01.172829105] (+0.000000575) arn-awallin-mint-l3 tracetest:first_tp: { cpu_id = 5 }, { my_string_field = "test", my_integer_field = 999 }</div><div>Snapshot recorded successfully for session test</div><div>168</div><div>[13:37:01.172021557] (+?.?????????) arn-awallin-mint-l3 ust_baddr_statedump:soinfo: { cpu_id = 7 }, { baddr = 0x7FFF653FE000, sopath = "[vdso]", size = 0, mtime = -1 }</div><div>[13:37:01.220074165] (+0.000000553) arn-awallin-mint-l3 tracetest:first_tp: { cpu_id = 6 }, { my_string_field = "test", my_integer_field = 999 }</div><div>Waiting for data availability</div><div>Tracing stopped for session test</div><div>Session test destroyed</div></div></div><div><br></div><div>the result from the run on older versions of lttng creates bigger and bigger event traces until reaching max size.<br></div><div><br></div><div>I have tested this on different architectures, with different buffer sizes and number of buffer<br></div><div><br></div><div>Regards<br clear="all"><div><div class="gmail_signature">Anders Wallin</div></div>
</div></div>