<div dir="ltr">Thanks for email, David!<div>Bug #770 has been opened :</div><div><a href="http://bugs.lttng.org/issues/770">http://bugs.lttng.org/issues/770</a><br></div><div><br></div><div class="gmail_extra"><br clear="all">
<div><div dir="ltr">-------------------------------------<br>Best regards,<br>Ruslan Uvashev<div><br></div><div><br></div></div></div>
<br><br><div class="gmail_quote">On Mon, Mar 24, 2014 at 8:01 AM,  <span dir="ltr"><<a href="mailto:dgoulet@efficios.com" target="_blank">dgoulet@efficios.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
On 23 Mar (20:45:01), Ruslan Uvashev wrote:<br>
> Hello lttng developers,<br>
<br>
Hi Ruslan,<br>
<br>
I have to say that you found quite a nice and important bug! :) I can<br>
reproduce it here in no time so can you please open an issue on<br>
<a href="http://bugs.lttng.org" target="_blank">bugs.lttng.org</a> in the lttng-tools project and flag it high?<br>
<br>
You basically just need to add the steps to reproduce and the version of<br>
tools you are using. I'll link this email in the archive to the issue<br>
you will open.<br>
<br>
Big thanks!<br>
David<br>
<div><div class="h5"><br>
><br>
> While looking at UST example in  "lttng-ust/doc/examples/easy-ust" i<br>
> noticed that waiting for data availability never ends if tracing has never<br>
> been started for UST.<br>
><br>
> I would like to ask you if it is an issue/bug and if it is need to be fixed?<br>
><br>
> Steps:<br>
> 1) create session<br>
> 2) enable UST event<br>
> 3) DO NOT start tracing<br>
> 4) start application and then stop it<br>
> 5) stop tracing <<< here tracing will never stop.<br>
><br>
> Thoughts:<br>
> This is valid only for UST.<br>
> Kernel is ok because it seems that kernel trace files are opened after<br>
> tracing is started while UST trace files are opened during application<br>
> registration.<br>
><br>
> /*<br>
>  * An empty output file is not valid. We need at least one packet<br>
>  * generated per stream, even if it contains no event, so it<br>
>  * contains at least one packet header.<br>
>  */<br>
> if (stream->output_written == 0) {<br>
> pthread_mutex_unlock(&stream->lock);<br>
> goto data_pending;<br>
> }<br>
><br>
><br>
><br>
> logs showing issue:<br>
><br>
> rusty@u:~/code/lttng-tools$ lttng -V<br>
><br>
> lttng (LTTng Trace Control) 2.4.0-rc2 - Époque Opaque<br>
><br>
> rusty@u:~/code/lttng-tools$ lttng create<br>
> Session auto-20140323-202015 created.<br>
> Traces will be written in /home/rusty/lttng-traces/auto-20140323-202015<br>
> rusty@u:~/code/lttng-tools$ lttng enable-event sample_component:message -u<br>
> UST event sample_component:message created in channel channel0<br>
> rusty@u:~/code/lttng-tools$ ../lttng-ust/doc/examples/easy-ust/sample<br>
> ^C<br>
> rusty@u:~/code/lttng-tools$ lttng stop<br>
> Waiting for data<br>
> availability.................................................^C<br>
><br>
><br>
><br>
> I added a few printouts to lttng and consumer to understand the issue<br>
> better.<br>
><br>
> traces UST:<br>
><br>
> rusty@u:~/code/lttng-tools$ lttng create<br>
> Session auto-20140323-201048 created.<br>
> Traces will be written in /home/rusty/lttng-traces/auto-20140323-201048<br>
> rusty@u:~/code/lttng-tools$ lttng enable-event sample_component:message -u<br>
> UST event sample_component:message created in channel channel0<br>
> rusty@u:~/code/lttng-tools$ ../lttng-ust/doc/examples/easy-ust/sample<br>
> ^C<br>
> rusty@u:~/code/lttng-tools$ lttng stop<br>
> llm.ret_code = 81<br>
> Waiting for data availabilityllm.ret_code = 1<br>
> .llm.ret_code = 1<br>
> .llm.ret_code = 1<br>
> ^C<br>
><br>
><br>
> traces UST from daemon:<br>
><br>
> DEBUG1 [6362/6465]: Processing client command 24 (in process_client_msg()<br>
> at main.c:2703)<br>
> DEBUG1 [6362/6465]: Getting session auto-20140323-201048 by name (in<br>
> process_client_msg() at main.c:2782)<br>
> DEBUG2 [6362/6465]: Trying to find session by name auto-20140323-201048 (in<br>
> session_find_by_name() at session.c:169)<br>
> DEBUG3 [6362/6465]: Consumer data pending for id 1 (in<br>
> consumer_is_data_pending() at consumer.c:1083)<br>
> DEBUG1 [6495/6501]: Incoming command on sock (in<br>
> consumer_thread_sessiond_poll() at consumer.c:3068)<br>
> DEBUG1 [6495/6501]: UST consumer data pending command for id 1 (in<br>
> lttng_ustconsumer_recv_cmd() at ust-consumer.c:1177)<br>
> DEBUG1 [6495/6501]: Consumer data pending command on session id 1 (in<br>
> consumer_data_pending() at consumer.c:3491)<br>
> DEBUG1 [6495/6501]: >>> Go over stream_list_ht <<< (in<br>
> consumer_data_pending() at consumer.c:3525)<br>
> DEBUG1 [6495/6501]: >>> stream_try_lock(stream) ret = 1 <<< (in<br>
> consumer_data_pending() at consumer.c:3532)<br>
> DEBUG1 [6495/6501]: >>> cds_lfht_is_node_deleted(&stream->node.node) ret =<br>
> 0 <<< (in consumer_data_pending() at consumer.c:3545)<br>
> DEBUG1 [6495/6501]: >>> !!! stream->output_written == 0 !!! <<< (in<br>
> consumer_data_pending() at consumer.c:3553)<br>
> DEBUG1 [6495/6501]: received command on sock (in<br>
> consumer_thread_sessiond_poll() at consumer.c:3084)<br>
> DEBUG1 [6362/6465]: Consumer data is  pending for session id 1 (in<br>
> consumer_is_data_pending() at consumer.c:1119)<br>
> DEBUG1 [6362/6465]: Sending response (size: 16, retcode: Unknown error<br>
> code) (in thread_manage_clients() at main.c:3975)<br>
><br>
><br>
><br>
><br>
> traces kernel:<br>
><br>
> rusty@u:~/code/lttng-tools$ lttng create<br>
> Session auto-20140323-201349 created.<br>
> Traces will be written in /home/rusty/lttng-traces/auto-20140323-201349<br>
> rusty@u:~/code/lttng-tools$ lttng enable-event -a -k<br>
> All Kernel events are enabled in channel channel0<br>
> rusty@u:~/code/lttng-tools$ lttng stop<br>
> llm.ret_code = 81<br>
> Waiting for data availabilityllm.ret_code = 0<br>
><br>
> Warning: Tracing already stopped for session auto-20140323-201349<br>
><br>
><br>
> traces kernel from daemon:<br>
><br>
> DEBUG1 [6362/6465]: Processing client command 24 (in process_client_msg()<br>
> at main.c:2703)<br>
> DEBUG1 [6362/6465]: Getting session auto-20140323-201349 by name (in<br>
> process_client_msg() at main.c:2782)<br>
> DEBUG2 [6362/6465]: Trying to find session by name auto-20140323-201349 (in<br>
> session_find_by_name() at session.c:169)<br>
> DEBUG3 [6362/6465]: Consumer data pending for id 2 (in<br>
> consumer_is_data_pending() at consumer.c:1083)<br>
> DEBUG1 [6576/6582]: Incoming command on sock (in<br>
> consumer_thread_sessiond_poll() at consumer.c:3068)<br>
> DEBUG1 [6576/6582]: Kernel consumer data pending command for id 2 (in<br>
> lttng_kconsumer_recv_cmd() at kernel-consumer.c:850)<br>
> DEBUG1 [6576/6582]: Consumer data pending command on session id 2 (in<br>
> consumer_data_pending() at consumer.c:3491)<br>
> DEBUG1 [6576/6582]: >>> Go over stream_list_ht <<< (in<br>
> consumer_data_pending() at consumer.c:3525)<br>
> DEBUG1 [6576/6582]: received command on sock (in<br>
> consumer_thread_sessiond_poll() at consumer.c:3084)<br>
> DEBUG1 [6362/6465]: Consumer data is NOT pending for session id 2 (in<br>
> consumer_is_data_pending() at consumer.c:1119)<br>
> DEBUG1 [6362/6465]: Sending response (size: 16, retcode: Unknown error<br>
> code) (in thread_manage_clients() at main.c:3975)<br>
><br>
><br>
><br>
> Thank you.<br>
><br>
> -------------------------------------<br>
> Best regards,<br>
> Ruslan Uvashev<br>
<br>
</div></div>> _______________________________________________<br>
> lttng-dev mailing list<br>
> <a href="mailto:lttng-dev@lists.lttng.org">lttng-dev@lists.lttng.org</a><br>
> <a href="http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev" target="_blank">http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev</a><br>
<br>
</blockquote></div><br></div></div>