<div dir="ltr"><div>Hello lttng developers,</div><div><br></div><div>While looking at UST example in  "lttng-ust/doc/examples/easy-ust" i noticed that waiting for data availability never ends if tracing has never been started for UST.</div>
<div><br></div><div>I would like to ask you if it is an issue/bug and if it is need to be fixed?</div><div><br></div><div>Steps:</div><div>1) create session</div><div>2) enable UST event</div><div>3) DO NOT start tracing</div>
<div>4) start application and then stop it</div><div>5) stop tracing <<< here tracing will never stop.</div><div><br></div><div>Thoughts:</div><div>This is valid only for UST.</div><div>Kernel is ok because it seems that kernel trace files are opened after tracing is started while UST trace files are opened during application registration. </div>
<div><br></div><div><div><span class="" style="white-space:pre">                        </span>/*</div><div><span class="" style="white-space:pre">                 </span> * An empty output file is not valid. We need at least one packet</div><div><span class="" style="white-space:pre">                  </span> * generated per stream, even if it contains no event, so it</div>
<div><span class="" style="white-space:pre">                    </span> * contains at least one packet header.</div><div><span class="" style="white-space:pre">                    </span> */</div><div><span class="" style="white-space:pre">                        </span>if (stream->output_written == 0) {</div>
<div><span class="" style="white-space:pre">                            </span>pthread_mutex_unlock(&stream->lock);</div><div><span class="" style="white-space:pre">                                </span>goto data_pending;<br></div><div><span class="" style="white-space:pre">                       </span>}</div>
</div><div><br></div><div><br></div><div><br></div><div>logs showing issue:<br></div><blockquote style="margin:0 0 0 40px;border:none;padding:0px"><div><div>rusty@u:~/code/lttng-tools$ lttng -V</div></div></blockquote><blockquote style="margin:0 0 0 40px;border:none;padding:0px">
<div><div>lttng (LTTng Trace Control) 2.4.0-rc2 - Époque Opaque</div></div></blockquote><blockquote style="margin:0px 0px 0px 40px;border:none;padding:0px"><div><div>rusty@u:~/code/lttng-tools$ lttng create</div></div><div>
<div>Session auto-20140323-202015 created.</div></div><div><div>Traces will be written in /home/rusty/lttng-traces/auto-20140323-202015</div></div><div><div>rusty@u:~/code/lttng-tools$ lttng enable-event sample_component:message -u</div>
</div><div><div>UST event sample_component:message created in channel channel0</div></div><div><div>rusty@u:~/code/lttng-tools$ ../lttng-ust/doc/examples/easy-ust/sample</div></div><div><div>^C</div></div><div><div>rusty@u:~/code/lttng-tools$ lttng stop</div>
</div><div><div>Waiting for data availability.................................................^C</div></div></blockquote><div><br></div><div><div><br></div><div>I added a few printouts to lttng and consumer to understand the issue better.</div>
</div><div><br></div><div>traces UST:<br></div><blockquote style="margin:0px 0px 0px 40px;border:none;padding:0px"><div>rusty@u:~/code/lttng-tools$ lttng create</div><div><div>Session auto-20140323-201048 created.</div></div>
<div><div>Traces will be written in /home/rusty/lttng-traces/auto-20140323-201048</div></div><div><div>rusty@u:~/code/lttng-tools$ lttng enable-event sample_component:message -u</div></div><div><div>UST event sample_component:message created in channel channel0</div>
</div><div><div>rusty@u:~/code/lttng-tools$ ../lttng-ust/doc/examples/easy-ust/sample</div></div><div><div>^C</div></div><div><div>rusty@u:~/code/lttng-tools$ lttng stop</div></div><div><div>llm.ret_code = 81</div></div><div>
<div>Waiting for data availabilityllm.ret_code = 1</div></div><div><div>.llm.ret_code = 1</div></div><div><div>.llm.ret_code = 1</div></div><div><div>^C<br></div></div></blockquote><div><br></div><div>traces UST from daemon:</div>
<blockquote style="margin:0px 0px 0px 40px;border:none;padding:0px"><div><div>DEBUG1 [6362/6465]: Processing client command 24 (in process_client_msg() at main.c:2703)</div></div><div><div>DEBUG1 [6362/6465]: Getting session auto-20140323-201048 by name (in process_client_msg() at main.c:2782)</div>
</div><div><div>DEBUG2 [6362/6465]: Trying to find session by name auto-20140323-201048 (in session_find_by_name() at session.c:169)</div></div><div><div>DEBUG3 [6362/6465]: Consumer data pending for id 1 (in consumer_is_data_pending() at consumer.c:1083)</div>
</div><div><div>DEBUG1 [6495/6501]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3068)</div></div><div><div>DEBUG1 [6495/6501]: UST consumer data pending command for id 1 (in lttng_ustconsumer_recv_cmd() at ust-consumer.c:1177)</div>
</div><div><div>DEBUG1 [6495/6501]: Consumer data pending command on session id 1 (in consumer_data_pending() at consumer.c:3491)</div></div><div><div>DEBUG1 [6495/6501]: >>> Go over stream_list_ht <<< (in consumer_data_pending() at consumer.c:3525)</div>
</div><div><div>DEBUG1 [6495/6501]: >>> stream_try_lock(stream) ret = 1 <<< (in consumer_data_pending() at consumer.c:3532)</div></div><div><div>DEBUG1 [6495/6501]: >>> cds_lfht_is_node_deleted(&stream->node.node) ret = 0 <<< (in consumer_data_pending() at consumer.c:3545)</div>
</div><div><div>DEBUG1 [6495/6501]: >>> !!! stream->output_written == 0 !!! <<< (in consumer_data_pending() at consumer.c:3553)</div></div><div><div>DEBUG1 [6495/6501]: received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3084)</div>
</div><div><div>DEBUG1 [6362/6465]: Consumer data is  pending for session id 1 (in consumer_is_data_pending() at consumer.c:1119)</div></div><div><div>DEBUG1 [6362/6465]: Sending response (size: 16, retcode: Unknown error code) (in thread_manage_clients() at main.c:3975)</div>
</div></blockquote><div><br></div><div><br></div><div><br></div><div>traces kernel:</div><blockquote style="margin:0px 0px 0px 40px;border:none;padding:0px"><div><div>rusty@u:~/code/lttng-tools$ lttng create </div></div><div>
<div>Session auto-20140323-201349 created.</div></div><div><div>Traces will be written in /home/rusty/lttng-traces/auto-20140323-201349</div></div><div><div>rusty@u:~/code/lttng-tools$ lttng enable-event -a -k</div></div>
<div><div>All Kernel events are enabled in channel channel0</div></div><div><div>rusty@u:~/code/lttng-tools$ lttng stop</div></div><div><div>llm.ret_code = 81</div></div><div><div>Waiting for data availabilityllm.ret_code = 0</div>
</div><div><div><br></div></div><div><div>Warning: Tracing already stopped for session auto-20140323-201349</div></div></blockquote><div><br></div><div>traces kernel from daemon:</div><blockquote style="margin:0px 0px 0px 40px;border:none;padding:0px">
<div><div>DEBUG1 [6362/6465]: Processing client command 24 (in process_client_msg() at main.c:2703)</div></div><div><div>DEBUG1 [6362/6465]: Getting session auto-20140323-201349 by name (in process_client_msg() at main.c:2782)</div>
</div><div><div>DEBUG2 [6362/6465]: Trying to find session by name auto-20140323-201349 (in session_find_by_name() at session.c:169)</div></div><div><div>DEBUG3 [6362/6465]: Consumer data pending for id 2 (in consumer_is_data_pending() at consumer.c:1083)</div>
</div><div><div>DEBUG1 [6576/6582]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3068)</div></div><div><div>DEBUG1 [6576/6582]: Kernel consumer data pending command for id 2 (in lttng_kconsumer_recv_cmd() at kernel-consumer.c:850)</div>
</div><div><div>DEBUG1 [6576/6582]: Consumer data pending command on session id 2 (in consumer_data_pending() at consumer.c:3491)</div></div><div><div>DEBUG1 [6576/6582]: >>> Go over stream_list_ht <<< (in consumer_data_pending() at consumer.c:3525)</div>
</div><div><div>DEBUG1 [6576/6582]: received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3084)</div></div><div><div>DEBUG1 [6362/6465]: Consumer data is NOT pending for session id 2 (in consumer_is_data_pending() at consumer.c:1119)</div>
</div><div><div>DEBUG1 [6362/6465]: Sending response (size: 16, retcode: Unknown error code) (in thread_manage_clients() at main.c:3975)</div></div></blockquote><div><br></div><div><br></div><div>Thank you.</div><br clear="all">
<div><div dir="ltr">-------------------------------------<br>Best regards,<br>Ruslan Uvashev<div><br></div></div></div>
</div>