Bug #363: lttng attempts to disable event but failed to do so, corresponding trace log do not match with what is expected - LTTng-tools - LTTng bugs repository

Actions

Copy link

Bug #363

closed

lttng attempts to disable event but failed to do so, corresponding trace log do not match with what is expected

Added by Tan le tran over 11 years ago. Updated over 11 years ago.

Status:

Resolved

Priority:

Normal

Assignee:

Target version:

LTTng - 2.1 stable

Start date:

10/03/2012

Due date:

% Done:

100%

Estimated time:

Description

Sceanrio: =========

/home/test_apps/demo-trace 60 &
lttng list -u
lttng create $SESSION_NAME -o /cluster/temp/sessiondir/$SESSION_NAME
lttng enable-event "ust_tests_demo2:l*" -u --filter ' intfield > 3'
lttng enable-event "ust_tests_demo2:loop" -u --filter ' intfield < 3'
Error: Invalid filter bytecode
Error: Setting filter for event ust_tests_demo2:loop: ' intfield < 3'
Error: UST app event ust_tests_demo2:loop disable failed for app (pid: 20616) and session handle 2 with ret -22
Error: Disabling event ust_tests_demo2:loop after filter error: Disable UST event failed

Why does it attempt to disable the second event ?

NOTE that when the demo app is executed after the session is started, then there is no 
    error given and the expected result (below) is obtained.
    If the demo app is running while the event is enabling, then the above error is given and
    the result trace log do not match with what is expected.

lttng start $SESSION_NAME;
lttng list $SESSION_NAME

#--- wait for demo to finish.
sleep 1
babeltrace --no-delta /cluster/temp/sessiondir/$SESSION_NAME

Result: =======
- see only event with "intfield = 4" .
Expected Result: ================
- event with: intfield =0,1,2,4

Extra note: ===========
- This might be related to ust bug-362 .
When trying to use wildcard to enabling an event, the following
error is given on the terminal from where the demo app is running:
[lttng filter] error linking wildcard bytecode

This bug has been fixed by not showing the above error but it
    looks like the after maths has not been clean up.

It might be leading to sessiond coredump later (this will be 
    reported in a separated bug report to help us keeping track
    of the issues).

Files

terminal.log (76.7 KB) terminal.log

terminal log + test instruction

Tan le tran, 10/03/2012 03:32 PM

Actions

Copy link

Updated by Tan le tran over 11 years ago

Commit used: ============
userspace : (sep6) a5a9f42 Ensure that read-side functions meet 10-line LGPL criterion
lttng-ust : (Oct03) c433c3c Fix: be quiet on filter linker error
lttng-tools: (sep28) 633d008 Fix: Metadata stream leak when received in consumer
babeltrace : (sep27) fef3bf2 Fix: Allow 64-bit packet offset

Actions

Copy link

Updated by David Goulet over 11 years ago

Status changed from New to Confirmed
Target version set to 2.1 stable

It is disabling the event because applying the filter failed.

This has been discussed in bug #343 where we agreed to that behavior.

For the rest, we'll have to look more in details but I can confirm the reproducibility.

Actions

Copy link

Updated by Tan le tran over 11 years ago

In Bug-343, we agreed to have the event disabled if the corresponding filter is invalid.
However, in this case, the filter is valid but it still attempts to disable it.

Actions

Copy link

Updated by David Goulet over 11 years ago

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA512
NotDashEscaped: You need GnuPG to verify this message

Right but the set filter command failed so the event is disabled...

We are looking into this a bit deeper to understand everything.

Will update the ticket once we have more information or a fix.

Thanks!
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.12 (GNU/Linux)

iQEcBAEBCgAGBQJQbcsAAAoJEELoaioR9I02zzIH/30EovSrC1UHgfteXGKUKkrW
8FIIxZk/NHWZK9w9zIpC1S+vGSnkPUReY5syZttQa4thUF9LZ+WqdLZsMxGhTfl
LBofUXWhQFfR5SU1fLcVlnLj3Uu7/U5b6+0ORoqOcjbcg4JcyrnVGuJZ48VTvIq0
kxtObwPiKGlzye9E7jqlzSuP+I5DrqxNyjz8aJGCjbchF4FB7cpLLhUlmSBp658y
yplRlZImIOwbo+tzZ1Slr1blb2w2Ua9Vr64aQk5Kmesmb0ILx/xj6jwMfoYWZqW
rE8FXJFYP+nuv/TAb/vprkXzjzsLQJGbYmPbyvG9m8uhfrRZeP/LoiQiQu9XG4w=
=DB4K
-----END PGP SIGNATURE-----

Actions

Copy link

Updated by David Goulet over 11 years ago

Ok, a note here:

$ lttng enable-event "ust_tests_demo2:l*" -u --filter ' intfield > 3' [VALID]
$ lttng enable-event "ust_tests_demo2:loop" -u --filter ' intfield < 3' [INVALID]

The l* enables the loop event so the second command should fail with "UST event already exist".

However, the session daemon returns "OK" if the UST tracer replies back EEXIST but this is not good considering this use case. So, I've made a patch that removes that condition and only set filter if the event was successfully enabled. This means that now enabling the same event twice will return an error on the second enable which is fine.

Pushing the patch in a jiffy. Reopen the ticket if this does not fix the issue here or partially fix it.

Thanks!

Actions

Copy link