[lttng-dev] lttng create freezes sometimes

[lttng-dev] lttng create freezes sometimes

[Sébastien Barthélémy]

Hello Mathieu,

2012/1/25 Mathieu Desnoyers <compudj at krystal.dyndns.org>:
> Please try with commit:
>
> commit 5a532b6873b6d619381c0188b91e48106e639808
> Author: Mathieu Desnoyers <mathieu.desnoyers at efficios.com>
> Date: ? Wed Jan 25 09:39:28 2012 -0500
>
> ? ?Fix lttng sessiond spawn wait race
>
> ? ?If the child is scheduled before the parent, using "pause()" in the
> ? ?parent could be executed after the signal has been handled: that's
> ? ?entirely racy. Use a proper signal handler and flag to handle this
> ? ?racelessly.
>
> ? ?Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers at efficios.com>
>
> Let me know how it works,

It works, thanks! I can run the following without any failure:

$ for i in {1..100}; do killall lttng-sessiond; sleep 1; echo "$i";
lttng create;done

However, if I remove the sleep, I get 7 other failures.
Likely race conditions between the kill and the subsequent start,
which is an unlikely use pattern.

Here they are anyway:

17
==> like 60

31
Spawning a session daemon
chmod: No such file or directory
Error: Session daemon died (exit status 0)

33
==> like 89

60
Spawning a session daemon
rm: cannot remove `/home/nao/.lttng': Directory not empty
Session auto-20120126-122706 created.
Traces will be written in /home/nao/lttng-traces/auto-20120126-122706

75
Spawning a session daemon
LTTng Trace Control 2.0-pre18

usage: lttng [options] <command>

Options:
  -h, --help             Show this help
  -g, --group NAME       Unix tracing group name. (default: tracing)
  -v, --verbose          Verbose mode
  -q, --quiet            Quiet mode
  -n, --no-sessiond      Don't spawn a session daemon
      --sessiond-path    Session daemon full path
      --list-options     Simple listing of lttng options
      --list-commands    Simple listing of lttng commands

Commands:
    add-context     Add context to event or/and channel
    calibrate       Quantify LTTng overhead
    create          Create tracing session
    destroy         Teardown tracing session
    enable-channel  Enable tracing channel
    enable-event    Enable tracing event
    disable-channel Disable tracing channel
    disable-event   Disable tracing event
    list            List possible tracing options
    set-session     Set current session name
    start           Start tracing
    stop            Stop tracing
    version         Show version information

Please see the lttng(1) man page for full documentation.
See http://lttng.org for updates, bug reports and news.


85
Spawning a session daemon
rm: cannot remove `/home/nao/.lttng': Is a directory
Session auto-20120126-122708 created.
Traces will be written in /home/nao/lttng-traces/auto-20120126-122708

89
epoll_wait: Bad file descriptor
Spawning a session daemon
Session auto-20120126-122709 created.
Traces will be written in /home/nao/lttng-traces/auto-20120126-122709

I also got some

$ killall lttng-sessiond ; lttng create
Spawning a session daemon
bind: No such file or directory
Error: Session daemon died (exit status 0)

Regards,

-- S?bastien

[lttng-dev] lttng create freezes sometimes

[David Goulet]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1



On 12-01-26 08:19 AM, S?bastien Barth?l?my wrote:
> Hello Mathieu,
> 
> 2012/1/25 Mathieu Desnoyers <compudj at krystal.dyndns.org>:
>> Please try with commit:
>>
>> commit 5a532b6873b6d619381c0188b91e48106e639808
>> Author: Mathieu Desnoyers <mathieu.desnoyers at efficios.com>
>> Date:   Wed Jan 25 09:39:28 2012 -0500
>>
>>    Fix lttng sessiond spawn wait race
>>
>>    If the child is scheduled before the parent, using "pause()" in the
>>    parent could be executed after the signal has been handled: that's
>>    entirely racy. Use a proper signal handler and flag to handle this
>>    racelessly.
>>
>>    Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers at efficios.com>
>>
>> Let me know how it works,
> 
> It works, thanks! I can run the following without any failure:
> 
> $ for i in {1..100}; do killall lttng-sessiond; sleep 1; echo "$i";
> lttng create;done
> 
> However, if I remove the sleep, I get 7 other failures.
> Likely race conditions between the kill and the subsequent start,
> which is an unlikely use pattern.

Hmmmm... yes looks like a race. I can't get any errors on my side... I even bump
it up to 1000 and still nothing... It seems your system is quite a challenge for
us! :)

> 
> Here they are anyway:
> 
> 17
> ==> like 60
> 
> 31
> Spawning a session daemon
> chmod: No such file or directory
> Error: Session daemon died (exit status 0)

This is most irregular since chmod() is *always* done after a mkdir, a socket
creation or shm open....

> 
> 33
> ==> like 89
> 
> 60
> Spawning a session daemon
> rm: cannot remove `/home/nao/.lttng': Directory not empty
> Session auto-20120126-122706 created.
> Traces will be written in /home/nao/lttng-traces/auto-20120126-122706

Again here, we use "rm -rf" for now ... how can you get this kind of error
message with "-rf" ....?

Looking at the rest, you have a bind() error, Bad file descriptor and more "no
such file or dir...". Is your open files limit is very low? Maybe there is a
couple of place where we don't handle well the maximum open files error.

Thanks
David

> 
> 75
> Spawning a session daemon
> LTTng Trace Control 2.0-pre18
> 
> usage: lttng [options] <command>
> 
> Options:
>   -h, --help             Show this help
>   -g, --group NAME       Unix tracing group name. (default: tracing)
>   -v, --verbose          Verbose mode
>   -q, --quiet            Quiet mode
>   -n, --no-sessiond      Don't spawn a session daemon
>       --sessiond-path    Session daemon full path
>       --list-options     Simple listing of lttng options
>       --list-commands    Simple listing of lttng commands
> 
> Commands:
>     add-context     Add context to event or/and channel
>     calibrate       Quantify LTTng overhead
>     create          Create tracing session
>     destroy         Teardown tracing session
>     enable-channel  Enable tracing channel
>     enable-event    Enable tracing event
>     disable-channel Disable tracing channel
>     disable-event   Disable tracing event
>     list            List possible tracing options
>     set-session     Set current session name
>     start           Start tracing
>     stop            Stop tracing
>     version         Show version information
> 
> Please see the lttng(1) man page for full documentation.
> See http://lttng.org for updates, bug reports and news.
> 
> 
> 85
> Spawning a session daemon
> rm: cannot remove `/home/nao/.lttng': Is a directory
> Session auto-20120126-122708 created.
> Traces will be written in /home/nao/lttng-traces/auto-20120126-122708
> 
> 89
> epoll_wait: Bad file descriptor
> Spawning a session daemon
> Session auto-20120126-122709 created.
> Traces will be written in /home/nao/lttng-traces/auto-20120126-122709
> 
> I also got some
> 
> $ killall lttng-sessiond ; lttng create
> Spawning a session daemon
> bind: No such file or directory
> Error: Session daemon died (exit status 0)
> 
> Regards,
> 
> -- S?bastien
> 
> _______________________________________________
> lttng-dev mailing list
> lttng-dev at lists.lttng.org
> http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
> 
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.10 (GNU/Linux)

iQEcBAEBAgAGBQJPItYmAAoJEELoaioR9I02CkkIAKhmpVMx3PjflWd587qNha0x
Pf/sdvmzHEoE/lf4rhCzeBSUkmvD6NRVdcsZvmz/LFY4s6oPIiGp5lVqZWSjUofE
2MNgUQXcMnmw2pLtJNsxAWVht/mLAspavnCCqgDXO1PoU7Su0jeGXFzn+K1ze41u
weHXHIVs2/Jf8/zycgaesvA7MUOr2BCacoj1sV3MHrf1XpSrgC4s40qwiozJzYLl
Gwzepnvrpp1ZxwUi+N7l47K15SVtB8qCOVuBWf1jxhcEDkFes/DdalbWh99dzGJg
DkGWBKbU71djA1cRqVwNwlovEXxFbderpW+be3r1NZpkaWjFqbDdWkhAjTDzD3E=
=fdot
-----END PGP SIGNATURE-----

[lttng-dev] lttng create freezes sometimes

[Sébastien Barthélémy]

Hello,

2012/1/27 David Goulet <dgoulet at efficios.com>:
> On 12-01-26 08:19 AM, S?bastien Barth?l?my wrote:
>> It works, thanks! I can run the following without any failure:
>>
>> $ for i in {1..100}; do killall lttng-sessiond; sleep 1; echo "$i";
>> lttng create;done
>>
>> However, if I remove the sleep, I get 7 other failures.
>> Likely race conditions between the kill and the subsequent start,
>> which is an unlikely use pattern.
>
> Hmmmm... yes looks like a race. I can't get any errors on my side... I even bump
> it up to 1000 and still nothing...
>
> It seems your system is quite a challenge for us! :)

It is a 500MHz AMD Geode processor. I'm pretty sure your workstation has more
horsepower ;)


> This is most irregular since chmod() is *always* done after a mkdir, a socket
> creation or shm open....

I imagine the scheduler might not agree with our definition of after ;).

Wouldn't the following be possible?

lttng-sessiond1 is running. .lttng exists
lttng-sessiond2 creates .lttng (as it already exists, this is a no-op)
lttng-sessiond1 get killed. It deletes .lttng
lttng-sessiond2 tries to chmod .lttng, which does not exist anymore

>> 60
>> Spawning a session daemon
>> rm: cannot remove `/home/nao/.lttng': Directory not empty
>> Session auto-20120126-122706 created.
>> Traces will be written in /home/nao/lttng-traces/auto-20120126-122706
>
> Again here, we use "rm -rf" for now ... how can you get this kind of error
> message with "-rf" ....?

I dunno...

> Looking at the rest, you have a bind() error, Bad file descriptor and more "no
> such file or dir...". Is your open files limit is very low? Maybe there is a
> couple of place where we don't handle well the maximum open files error.

The limit is 1024. Quite usual no?

[lttng-dev] lttng create freezes sometimes

[David Goulet]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1



On 12-01-27 12:25 PM, S?bastien Barth?l?my wrote:
> Hello,
> 
> 2012/1/27 David Goulet <dgoulet at efficios.com>:
>> On 12-01-26 08:19 AM, S?bastien Barth?l?my wrote:
>>> It works, thanks! I can run the following without any failure:
>>>
>>> $ for i in {1..100}; do killall lttng-sessiond; sleep 1; echo "$i";
>>> lttng create;done
>>>
>>> However, if I remove the sleep, I get 7 other failures.
>>> Likely race conditions between the kill and the subsequent start,
>>> which is an unlikely use pattern.
>>
>> Hmmmm... yes looks like a race. I can't get any errors on my side... I even bump
>> it up to 1000 and still nothing...
>>
>> It seems your system is quite a challenge for us! :)
> 
> It is a 500MHz AMD Geode processor. I'm pretty sure your workstation has more
> horsepower ;)
> 

Ya I dev on i7 :P ... It's difficult for me to hit race condition due to slow
CPU/RAM access and this is why open source is so fantastic! Crowd sourcing the
corner cases :P :P

> 
>> This is most irregular since chmod() is *always* done after a mkdir, a socket
>> creation or shm open....
> 
> I imagine the scheduler might not agree with our definition of after ;).
> 
> Wouldn't the following be possible?
> 
> lttng-sessiond1 is running. .lttng exists
> lttng-sessiond2 creates .lttng (as it already exists, this is a no-op)
> lttng-sessiond1 get killed. It deletes .lttng
> lttng-sessiond2 tries to chmod .lttng, which does not exist anymore

You are WAY more awake than me! Actually, I'm talking with Mathieu on this issue
right now. It is probably exactly what's happening!

We'll try to come up with a fix today! I'll keep you inform

Thanks a lot!
David

> 
>>> 60
>>> Spawning a session daemon
>>> rm: cannot remove `/home/nao/.lttng': Directory not empty
>>> Session auto-20120126-122706 created.
>>> Traces will be written in /home/nao/lttng-traces/auto-20120126-122706
>>
>> Again here, we use "rm -rf" for now ... how can you get this kind of error
>> message with "-rf" ....?
> 
> I dunno...
> 
>> Looking at the rest, you have a bind() error, Bad file descriptor and more "no
>> such file or dir...". Is your open files limit is very low? Maybe there is a
>> couple of place where we don't handle well the maximum open files error.
> 
> The limit is 1024. Quite usual no?
> 
> _______________________________________________
> lttng-dev mailing list
> lttng-dev at lists.lttng.org
> http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
> 
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.10 (GNU/Linux)

iQEcBAEBAgAGBQJPIuBwAAoJEELoaioR9I02piYH/i4E58ATABiv4cWdOCnXg8yN
hECtzD/l3oQ64BRv+HmMKfac06jpK3cG3XmPq2Ncjdm+RE9IGgczgvcRG2hL21DS
f0pR+R+uqe/yqnb3xEYio6IiIov0o25qmSYEuAjLzY5nOqG7A1h5fnbgPL+FCoN3
uIbnMQx+eCP6GnOvuPaX7yB6Egwsz4bmUD/tfUqTVKB+q+9BfPuIDliWxINjj2iK
0lEaTYcgF9yax2tUbknQXpS0S72Q9wZ+JLDkLGqDcL0Qfp+dhEgIYQTfCAYZg7kK
HEoO8yIIpjyLJl+Dc0VuSgXVjsvSK/lEaf2r6HPApO/S1GWJh6CM7L0xXUk/6FU=
=05MT
-----END PGP SIGNATURE-----