[lttng-dev] Problem running lttng enable-channel shortly after lttng create

[Amit Margalit]

Hello,

I keep getting the following error from lttng enable-channel:

libust[2984/2986]: Error: Timed out waiting for lttng-sessiond (in 
lttng_ust_init() at lttng-ust-comm.c:1444)

The scenario is quite simple - during boot of the system, we create a 
session, enable a channel, etc., like this:

# /usr/bin/lttng-sessiond --no-kernel -b
Warning: No tracing group detected
# /usr/bin/lttng create nextra -o /local/traces/lttng/20140402123725
Session nextra created.
Traces will be written in /local/traces/lttng/20140402123725
# /usr/bin/lttng enable-channel channel0 -u --tracefile-size 67108864 
--tracefile-count 40 --buffers-uid --switch-timer 1000000 --num-subbuf 16 
--subbuf-size 262144
libust[2984/2986]: Error: Timed out waiting for lttng-sessiond (in 
lttng_ust_init() at lttng-ust-comm.c:1444)
Warning: No tracing group detected

The PID 2984 belongs to the lttng-consumerd. At that point in time I see 
the following in syslog:

2014/04/02 12:38:03.370576 kernel   error    nextra-6663235-module-1  [ 
56.376155] proc lttng-sessiond with pid 632 goes to delayed retry in 
epoll_wait(): start jiffies 4294904844, stop jiffies=4294906390 (+1546), 
expected final stop jiffies=9223372041149680651 (+9223372036854775807), 
next stop jiffies=9223372041149682197 (+9223372036854775807)
2014/04/02 12:38:03.399245 kernel   error    nextra-6663235-module-1  [ 
56.405166] proc lttng-sessiond with pid 632 goes to delayed retry in 
epoll_wait(): start jiffies 4294904844, stop jiffies=4294906397 (+1553), 
expected final stop jiffies=9223372041149680651 (+9223372036854775807), 
next stop jiffies=9223372041149682204 (+9223372036854775807)
2014/04/02 12:38:03.405700 kernel   error    nextra-6663235-module-1  [ 
56.411791] proc lttng-sessiond with pid 632 goes to delayed retry in 
epoll_wait(): start jiffies 4294904844, stop jiffies=4294906398 (+1554), 
expected final stop jiffies=9223372041149680651 (+9223372036854775807), 
next stop jiffies=9223372041149682205 (+9223372036854775807)

And finally, the command succeeds:

UST channel channel0 enabled for session nextra

My guess is that the boot sequence is loading some traced application 
before the channel is enabled, and the consumerd is started, which under 
heavy system load (exists during initial boot time) times out waiting for 
the sessiond. If that was the case, I could try to increase the timeout 
time, but that also delays my booting, which I cannot afford to do.

Suggestions?


Amit Margalit
IBM XIV - Storage Reinvented
XIV-NAS Development Team
Tel. 03-689-7774
Fax. 03-689-7230
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.lttng.org/pipermail/lttng-dev/attachments/20140402/27a2af21/attachment.html>