LTTng bugs repository: Issueshttps://bugs.lttng.org/https://bugs.lttng.org/themes/lttng/favicon/a.ico?14249722912024-02-21T17:04:43ZLTTng bugs repository
Redmine Babeltrace - Feature #1410 (New): Add pretty-print sink options to override how to format floatin...https://bugs.lttng.org/issues/14102024-02-21T17:04:43ZMathieu Desnoyersmathieu.desnoyers@efficios.com
<p>Babeltrace 2, just like its predecessor babeltrace 1.5, uses "%g" to print floating point numbers.</p>
<p>It would be useful to let users optionally override the formatting for floating point numbers, perhaps with a pretty print sink option. They could then choose if exponent notation should be used or not, choose the precision, etc.</p> Babeltrace - Bug #1397 (New): reserved identifier violationhttps://bugs.lttng.org/issues/13972023-10-26T18:56:27ZMarkus Elfring
<p>I would like to point out that a few identifiers do eventually not fit to the expected naming convention of the C language standard.<br /><a class="external" href="https://www.securecoding.cert.org/confluence/display/c/DCL37-C.+Do+not+declare+or+define+a+reserved+identifier">https://www.securecoding.cert.org/confluence/display/c/DCL37-C.+Do+not+declare+or+define+a+reserved+identifier</a></p>
<p>Would you like to adjust your selection for unique names?</p>
Examples:
<ul>
<li>__BT_IN_BABELTRACE_H<br /> <a class="external" href="https://github.com/efficios/babeltrace/blob/8a87cdbd41e2e04b1b64e9959751cdabe72281c1/include/babeltrace2/babeltrace.h#L13-L17">https://github.com/efficios/babeltrace/blob/8a87cdbd41e2e04b1b64e9959751cdabe72281c1/include/babeltrace2/babeltrace.h#L13-L17</a></li>
<li>_BABELTRACE_UTC_H<br /> <a class="external" href="https://github.com/efficios/babeltrace/blob/8a87cdbd41e2e04b1b64e9959751cdabe72281c1/src/compat/utc.h#L7-L8">https://github.com/efficios/babeltrace/blob/8a87cdbd41e2e04b1b64e9959751cdabe72281c1/src/compat/utc.h#L7-L8</a></li>
</ul> Babeltrace - Bug #1389 (New): src.ctf.fs crash with invalid tracehttps://bugs.lttng.org/issues/13892023-09-18T20:16:39ZSimon Marchisimon.marchi@polymtl.ca
<p>Using the attached trace, I get:</p>
<pre>
$ ./src/cli/babeltrace2 trace
09-18 16:15:58.978 335803 335803 E PLUGIN/CTF/MSG-ITER ctf_msg_iter_get_next_message@msg-iter.cpp:2715 [auto-disc-source-ctf-fs] Cannot handle state: msg-it-addr=0x613000000580, state=DSCOPE_EVENT_PAYLOAD_CONTINUE
09-18 16:15:58.978 335803 335803 F LIB/ASSERT-COND bt_lib_assert_cond_failed@assert-cond.c:63 Babeltrace 2 library postcondition not satisfied.
09-18 16:15:58.978 335803 335803 F LIB/ASSERT-COND bt_lib_assert_cond_failed@assert-cond.c:65 ------------------------------------------------------------------------
09-18 16:15:58.978 335803 335803 F LIB/ASSERT-COND bt_lib_assert_cond_failed@assert-cond.c:66 Condition ID: `post:message-iterator-class-next-method:no-error-if-no-error-status`.
09-18 16:15:58.978 335803 335803 F LIB/ASSERT-COND bt_lib_assert_cond_failed@assert-cond.c:68 Function: bt_message_iterator_class_next_method().
09-18 16:15:58.978 335803 335803 F LIB/ASSERT-COND bt_lib_assert_cond_failed@assert-cond.c:69 ------------------------------------------------------------------------
09-18 16:15:58.978 335803 335803 F LIB/ASSERT-COND bt_lib_assert_cond_failed@assert-cond.c:70 Error is:
09-18 16:15:58.978 335803 335803 F LIB/ASSERT-COND bt_lib_assert_cond_failed@assert-cond.c:72 Current thread has an error, but user function returned a non-error status: status=OK
09-18 16:15:58.978 335803 335803 F LIB/ASSERT-COND bt_lib_assert_cond_failed@assert-cond.c:75 Aborting...
</pre> Babeltrace - Bug #1388 (New): Assertion `this->active_stream_iter == 0` failedhttps://bugs.lttng.org/issues/13882023-09-08T18:57:03ZSimon Marchisimon.marchi@polymtl.ca
<p>Steps:</p>
<ol>
<li><code>lttng create my-session --live</code></li>
<li><code>lttng enable-event -u -a</code></li>
<li><code>lttng start</code></li>
<li><code>./src/cli/babeltrace2 'net://127.0.0.1/host/smarchi-efficios/my-session'</code></li>
<li>Run the hello app from the lttng-ust tests: <code>lttng-ust/tests/hello/hello</code></li>
<li>While events print on the babeltrace terminal, type ctrl-C</li>
</ol>
<p>I get:</p>
<p><code> (╯°□°)╯︵ ┻━┻ /home/smarchi/src/babeltrace/src/plugins/ctf/lttng-live/lttng-live.cpp:214: ~lttng_live_msg_iter(): Assertion `this->active_stream_iter == 0` failed.</code></p> Babeltrace - Bug #1384 (New): Assertion `bt_value_get_type(map) == BT_VALUE_TYPE_MAP` failshttps://bugs.lttng.org/issues/13842023-08-08T18:07:42ZErica Bugden
<p>Hello! I triggered an internal assertion while trying to, presumably incorrectly, query the lttng-live component class.</p>
<a name="Software"></a>
<h1 >Software<a href="#Software" class="wiki-anchor">¶</a></h1>
<ul>
<li>lttng tools: <code>lttng (LTTng Trace Control) 2.14.0-pre - O-Beer - v2.12.0-rc1-1528-g5983bb6d3</code></li>
<li>babeltrace2: <code>Babeltrace 2.1.0-rc1 "Codename TBD" [v1.2.0-3704-gdbea6be2]</code> (configured with plugins, python bindings support)</li>
</ul>
<a name="Procedure"></a>
<h1 >Procedure<a href="#Procedure" class="wiki-anchor">¶</a></h1>
<ul>
<li>Start root session daemon: <code>$sudo lttng-sessiond --daemonize</code></li>
<li>Create live session: <code>$lttng create my-session --live</code></li>
<li>Enable events: <code>$lttng enable-event --kernel sched-switch,sched_process_fork</code></li>
<li>Start tracing <code>$lttng start</code></li>
<li>Run python script: <code>python3 lttng-live.py</code> (see below)
<ul>
<li>Assertion</li>
</ul></li>
</ul>
<a name="Python-script"></a>
<h1 >Python script<a href="#Python-script" class="wiki-anchor">¶</a></h1>
<p>Note: The script is noisy as some code/comments are irrelevant/incorrect/inconsistent. (It's originally based on the query example in the Python bindings documentation.)</p>
<pre>
import bt2
import sys
# Get the `source.ctf.fs` component class from the `ctf` plugin.
# `source.ctf.lttng-live` component class instead
# (list plugins/components with $babeltrace2 list-plugins)
comp_cls = bt2.find_plugin('ctf').source_component_classes['lttng-live']
# The `babeltrace.support-info` query operation expects a `type`
# parameter (set to `directory` here) and an `input` parameter (the
# actual path or string to check, in this case the first command-line
# argument).
#
# See `babeltrace2-query-babeltrace.support-info(7)`.
params = {
'url': 'net://localhost/host/luna/my-session'
}
'''
params = {
'type': 'string',
'input': sys.argv[1],
}
'''
# Create a query executor.
#
# This is the environment in which query operations happens. The
# queried component class has access to this executor, for example to
# retrieve the query operation's logging level.
query_exec = bt2.QueryExecutor(comp_cls, 'sessions',
'inputs=net://localhost/host/luna/my-session')
'''
query_exec = bt2.QueryExecutor(comp_cls, 'babeltrace.support-info',
params)
'''
# Query the component class through the query executor.
#
# This method returns the result.
result = query_exec.query()
# Print the result.
print(result)
# Try to iterate on the trace.
'''
for msg in bt2.TraceCollectionMessageIterator('net://localhost/host/luna/my-session'):
if type(msg) is bt2._EventMessageConst:
print(msg.event.name)
'''
</pre>
<p>If I remember correctly, <strong>the script line change that triggered the assertion was expressing the query parameters directly as a string</strong> (rather than a dictionary). As in this:</p>
<pre>
query_exec = bt2.QueryExecutor(comp_cls, 'sessions',
'inputs=net://localhost/host/luna/my-session')
</pre>
<p>instead of this:</p>
<pre>
params = {
'url': 'net://localhost/host/luna/my-session'
}
query_exec = bt2.QueryExecutor(comp_cls, 'sessions',
params)
</pre>
<a name="Output"></a>
<h1 >Output<a href="#Output" class="wiki-anchor">¶</a></h1>
<pre>
erica@luna:~$ python3 lttng-live.py
(╯°□°)╯︵ ┻━┻ param-validation.c:196: validate_map_value(): Assertion `bt_value_get_type(map) == BT_VALUE_TYPE_MAP` failed.
Aborted (core dumped)
</pre> Babeltrace - Bug #1374 (New): Babeltrace fails to read trace with no data stream type ID when the...https://bugs.lttng.org/issues/13742023-04-26T17:57:32ZErica Bugden
<p>Babeltrace is not able to read a trace that does not contain data stream IDs (empty packet header) when the metadata specifies an ID for the stream. Trace Compass is also unable to read this trace. If the lines mentioning the stream ID are removed from the metadata, then babeltrace is able to read the trace.</p>
<a name="Does-this-need-to-be-fixed"></a>
<h3 >Does this need to be fixed?<a href="#Does-this-need-to-be-fixed" class="wiki-anchor">¶</a></h3>
<p>This was first reported as a barectf issue <a class="external" href="https://github.com/efficios/barectf/issues/28">https://github.com/efficios/barectf/issues/28</a> , but after further consideration the issue appears to be in a grey area in the CTF 1.8 specification. Whether it is the CTF generator's (barectf) responsibility or the CTF reader's responsibility is up for debate.</p>
<p>The superfluous metadata information need not prevent the trace from being parsed. For example, yactfr <a class="external" href="https://github.com/eepp/yactfr">https://github.com/eepp/yactfr</a> is able to read the trace. However, considering that:</p>
<ul>
<li>At least two CTF readers (babeltrace and Trace Compass) cannot read the trace, and</li>
<li>It is easy to fix in barectf (Proposed fix: <a class="external" href="https://review.lttng.org/c/barectf/+/9868">https://review.lttng.org/c/barectf/+/9868</a> )</li>
</ul>
<p>this is not a high priority issue in babeltrace.</p>
<a name="Context"></a>
<h1 >Context<a href="#Context" class="wiki-anchor">¶</a></h1>
<p>- Background and reproducer: barectf github issue <a class="external" href="https://github.com/efficios/barectf/issues/28">https://github.com/efficios/barectf/issues/28</a> <br />- Background and specification discussion: barectf fix <a class="external" href="https://review.lttng.org/c/barectf/+/9868">https://review.lttng.org/c/barectf/+/9868</a></p> Babeltrace - Bug #1351 (Feedback): Babeltrace2 failes at a negative clock `offset`https://bugs.lttng.org/issues/13512022-03-21T06:30:01ZHeng Guo
<p>Below lttng packages are using in our project.<br />Lttng_tools: 2.12.3<br />Lttng_ust: 2.12.1<br />Babeltrace: 2.0.3</p>
<p>Get below babletrace2 error when we call "babeltrace2 lts21/live", lts21/live is folder name of trace data.<br /><pre>
01-02 06:43:13.098 1029 1029 E PLUGIN/CTF/META/IR-VISITOR get_unary_unsigned@visitor-generate-ir.c:800 [auto-disc-source-ctf-fs] At line 43 in metadata stream: Invalid constant unsigned integer.
01-02 06:43:13.099 1029 1029 E PLUGIN/CTF/META/IR-VISITOR visit_clock_decl_entry@visitor-generate-ir.c:4356 [auto-disc-source-ctf-fs] At line 43 in metadata stream: Unexpected unary expression for clock class's `offset` attribute.
01-02 06:43:13.099 1029 1029 E PLUGIN/CTF/META/IR-VISITOR visit_clock_decl@visitor-generate-ir.c:4530 [auto-disc-source-ctf-fs] At line 43 in metadata stream: Cannot visit clock class's entry: ret=-22
01-02 06:43:13.099 1029 1029 E PLUGIN/CTF/META/IR-VISITOR ctf_visitor_generate_ir_visit_node@visitor-generate-ir.c:4773 [auto-disc-source-ctf-fs] At line 44 in metadata stream: Cannot visit clock class: ret=-22
01-02 06:43:13.099 1029 1029 E PLUGIN/CTF/META/DECODER ctf_metadata_decoder_append_content@decoder.c:336 [auto-disc-source-ctf-fs] Failed to visit AST node to create CTF IR objects: mdec-addr=0xa245b0, ret=-22
01-02 06:43:13.099 1029 1029 E PLUGIN/SRC.CTF.FS/META ctf_fs_metadata_set_trace_class@metadata.c:128 [auto-disc-source-ctf-fs] Cannot update metadata decoder's content.
01-02 06:43:13.099 1029 1029 E PLUGIN/SRC.CTF.FS ctf_fs_component_create_ctf_fs_trace_one_path@fs.c:1204 [auto-disc-source-ctf-fs] Cannot create trace for `/root/lts21/live/xmu03/session-19700101-000023/ust/uid/0/32-bit`.
01-02 06:43:13.099 1029 1029 W LIB/GRAPH add_component_with_init_method_data@graph.c:973 Component initialization method failed: status=ERROR, comp-addr=0xa1be90, comp-name="auto-disc-source-ctf-fs", comp-log-level=WARNING, comp-class-type=SOURCE, comp-class-name="fs", comp-class-partial-descr="Read CTF traces from the file sy", comp-class-is-frozen=0, comp-class-so-handle-addr=0xa278f8, comp-class-so-handle-path="/usr/lib/babeltrace2/plugins/babeltrace-plugin-ctf.so", comp-input-port-count=0, comp-output-port-count=0
01-02 06:43:13.099 1029 1029 E CLI cmd_run_ctx_create_components_from_config_components@babeltrace2.c:2295 Cannot create component: plugin-name="ctf", comp-cls-name="fs", comp-cls-type=1, comp-name="auto-disc-source-ctf-fs"
01-02 06:43:13.099 1029 1029 E CLI cmd_run@babeltrace2.c:2480 Cannot create components.
ERROR: [Babeltrace CLI] (../../../git/src/cli/babeltrace2.c:2480)
Cannot create components.
CAUSED BY [Babeltrace CLI] (../../../git/src/cli/babeltrace2.c:2295)
Cannot create component: plugin-name="ctf", comp-cls-name="fs", comp-cls-type=1, comp-name="auto-disc-source-ctf-fs"
CAUSED BY [libbabeltrace2] (../../../../git/src/lib/graph/graph.c:973)
Component initialization method failed: status=ERROR, comp-addr=0xa1be90, comp-name="auto-disc-source-ctf-fs", comp-log-level=WARNING, comp-class-type=SOURCE, comp-class-name="fs", comp-class-partial-descr="Read CTF traces from the file sy", comp-class-is-frozen=0, comp-class-so-handle-addr=0xa278f8, comp-class-so-handle-path="/usr/lib/babeltrace2/plugins/babeltrace-plugin-ctf.so", comp-input-port-count=0, comp-output-port-count=0
CAUSED BY [auto-disc-source-ctf-fs: 'source.ctf.fs'] (../../../../../git/src/plugins/ctf/fs-src/fs.c:1204)
Cannot create trace for `/root/lts21/live/xmu03/session-19700101-000023/ust/uid/0/32-bit`.
</pre></p>
<p>Seems the same issue to <a class="external" href="https://bugs.lttng.org/issues/1277">https://bugs.lttng.org/issues/1277</a>, but there is not fix patch yet.<br />We have the same issue on babeltrace version 1.5.8 too, <a class="external" href="https://bugs.lttng.org/issues/1350">https://bugs.lttng.org/issues/1350</a></p>
<p>We fix it with the attached patch: which is based on latest branch: stable-2.0.<br />Please help check it.</p>
<p>Thanks.</p> Babeltrace - Bug #1350 (Feedback): Babeltrace failes at a negative clock `offset`https://bugs.lttng.org/issues/13502022-03-17T07:08:14ZHeng Guo
<p>Below lttng packages are using in our project.<br />Lttng_tools: 2.12.3<br />Lttng_ust: 2.12.1<br />Babeltrace: 1.5.8</p>
<p>1.<br />In Lttng live mode, we get below babletrace error when we call "babeltrace --clock-date --no-delta -i lttng-live net://localhost/host/xxxxx/session" <br /><pre>
[error] ctf_clock_declaration_visit: unexpected unary expression for clock offset
[error] ctf_visitor_construct_metadata: clock declaration error
[error] Error in CTF metadata constructor -22
[error] [Context] Cannot open_mmap_trace of format ctf.
[error] Error adding trace
[warning] [Context] Cannot open_trace of format lttng-live at path net://localhost/host/xxxxx/session.
[warning] [Context] cannot open trace "net://localhost/host/xxxxx/session" for reading.
[error] opening trace "net://localhost/host/xxxxx/session" for reading.
[error] none of the specified trace paths could be opened.
</pre></p>
<p>Finally we port commit: 61cf588beae752e5ddfc60b6b5310f769ac9e852 from master branch to 1.5.8, then the issue is fixed.</p>
<p>2. With this commit: 61cf588beae752e5ddfc60b6b5310f769ac9e852, we find test case: tests/bin/intersection/test_intersection fails.<br />1) The 1st reason is wrong clock offset_s = 1351530929945824323, refer to below :<br /><pre>
cat tests/ctf-traces/intersection/3eventsintersect/metadata
.....
clock {
name = test_clock;
uuid = "7b9e2f2a-530e-4ab1-816f-0831b5c09140";
description = "This is a test clock";
freq = 1000000000;
precision = 10;
offset_s = 1351530929945824323;
offset = 0;
absolute = TRUE;
};
</pre><br />There is a overflow in clock_offset_ns() if clock offset_s = 1351530929945824323.<br /><pre>
static inline
uint64_t clock_offset_ns(struct ctf_clock *clock)
{
return clock->offset_s * 1000000000ULL
+ clock_cycles_to_ns(clock, clock->offset);
}
</pre></p>
<p>Double check the babeltrace 2, it is already fixed to "offset_s = 13515309;" in tests/data/ctf-traces/intersection/3eventsintersect/metadata</p>
<p>2) The 2nd reason is the regression of commit: 61cf588beae752e5ddfc60b6b5310f769ac9e852. uint64_t should be changed to int64_t in some codes related to option "--stream-intersection".<br />Attach 3 related patches based on branch remotes/origin/stable-1.5.</p>
<p>So why commit 61cf588beae752e5ddfc60b6b5310f769ac9e852 is not merged to branch 1.5? Is there any reason or side effect of this commit?</p> Babeltrace - Bug #1299 (Confirmed): babeltrace2 re-uses prior event string rather than expected e...https://bugs.lttng.org/issues/12992021-03-04T18:49:50ZMathieu Desnoyersmathieu.desnoyers@efficios.com
<p>Trying to reproduce the page fault scenario for an openat() event. Note that the behavior of generating a page fault may be toolchain-specific (linker-specific):</p>
<p>Test program "do-pagefault-open":</p>
<p>#include <stdio.h><br />#include <sys/types.h><br />#include <sys/stat.h><br />#include <fcntl.h></p>
<p>const char *str = "/tmp/blah";<br />const char *str2 = "/tmp/blah2";</p>
<p>int main()
{<br /> open(str, O_RDWR);<br /> perror("first");<br /> open(str2, O_RDWR);<br /> perror("second");<br /> return 0;<br />}</p>
<p>then trace with:</p>
<p>lttng-trace ./do-pagefault-open</p>
<p>Relevant events with babeltrace2 (grepping for 'openat'):</p>
<p>[13:47:12.296015570] (+0.000015421) thinkos syscall_entry_openat: { cpu_id = 3 }, { procname = "do-pagefault-op", vpid = 31576, vtid = 31576 }, { dfd = -100, filename = "/etc/ld.so.cache", flags = ( "O_CLOEXEC" : container = 524288 ), mode = ( <unknown> : container = 0 ) }<br />[13:47:12.296029004] (+0.000013434) thinkos syscall_exit_openat: { cpu_id = 3 }, { procname = "do-pagefault-op", vpid = 31576, vtid = 31576 }, { ret = 3 }<br />[13:47:12.296116608] (+0.000058899) thinkos syscall_entry_openat: { cpu_id = 3 }, { procname = "do-pagefault-op", vpid = 31576, vtid = 31576 }, { dfd = -100, filename = "/lib/x86_64-linux-gnu/libc.so.6", flags = ( "O_CLOEXEC" : container = 524288 ), mode = ( <unknown> : container = 0 ) }<br />[13:47:12.296126244] (+0.000009636) thinkos syscall_exit_openat: { cpu_id = 3 }, { procname = "do-pagefault-op", vpid = 31576, vtid = 31576 }, { ret = 3 }<br />[13:47:12.296706313] (+0.000096888) thinkos syscall_entry_openat: { cpu_id = 3 }, { procname = "do-pagefault-op", vpid = 31576, vtid = 31576 }, { dfd = -100, filename = "/lib/x86_64-linux-gnu/libc.so.6", flags = ( "O_RDWR" : container = 2 ), mode = ( <unknown> : container = 0 ) }<br />[13:47:12.296717797] (+0.000011484) thinkos syscall_exit_openat: { cpu_id = 3 }, { procname = "do-pagefault-op", vpid = 31576, vtid = 31576 }, { ret = -2 }<br />[13:47:12.296954228] (+0.000005481) thinkos syscall_entry_openat: { cpu_id = 3 }, { procname = "do-pagefault-op", vpid = 31576, vtid = 31576 }, { dfd = -100, filename = "/tmp/blah2", flags = ( "O_RDWR" : container = 2 ), mode = ( <unknown> : container = 0 ) }<br />[13:47:12.296960451] (+0.000006223) thinkos syscall_exit_openat: { cpu_id = 3 }, { procname = "do-pagefault-op", vpid = 31576, vtid = 31576 }, { ret = -2 }</p>
<p>Same trace with babeltrace 1:</p>
<p>[warning] Unknown value 0 in enum.<br />[warning] Unknown value 0 in enum.<br />[warning] Unknown value 3 in enum.<br />[warning] Unknown value 5 in enum.<br />[warning] Unknown value 129 in enum.<br />[warning] Unknown value 129 in enum.<br />[warning] Unknown value 3 in enum.<br />[warning] Unknown value 129 in enum.<br />[warning] Unknown value 3 in enum.<br />[warning] Unknown value 3 in enum.<br />[13:47:12.296015570] (+0.000015421) thinkos syscall_entry_openat: { cpu_id = 3 }, { procname = "do-pagefault-op", vpid = 31576, vtid = 31576 }, { dfd = -100, filename = "/etc/ld.so.cache", flags = ( "O_CLOEXEC" : container = 524288 ), mode = ( <unknown> : container = 0 ) }<br />[13:47:12.296029004] (+0.000013434) thinkos syscall_exit_openat: { cpu_id = 3 }, { procname = "do-pagefault-op", vpid = 31576, vtid = 31576 }, { ret = 3 }<br />[13:47:12.296116608] (+0.000058899) thinkos syscall_entry_openat: { cpu_id = 3 }, { procname = "do-pagefault-op", vpid = 31576, vtid = 31576 }, { dfd = -100, filename = "/lib/x86_64-linux-gnu/libc.so.6", flags = ( "O_CLOEXEC" : container = 524288 ), mode = ( <unknown> : container = 0 ) }<br />[13:47:12.296126244] (+0.000009636) thinkos syscall_exit_openat: { cpu_id = 3 }, { procname = "do-pagefault-op", vpid = 31576, vtid = 31576 }, { ret = 3 }<br />[warning] Unknown value 0 in enum.<br />[warning] Unknown value 0 in enum.<br />[13:47:12.296706313] (+0.000096888) thinkos syscall_entry_openat: { cpu_id = 3 }, { procname = "do-pagefault-op", vpid = 31576, vtid = 31576 }, { dfd = -100, filename = "", flags = ( "O_RDWR" : container = 2 ), mode = ( <unknown> : container = 0 ) }<br />[13:47:12.296717797] (+0.000011484) thinkos syscall_exit_openat: { cpu_id = 3 }, { procname = "do-pagefault-op", vpid = 31576, vtid = 31576 }, { ret = -2 }<br />[13:47:12.296954228] (+0.000005481) thinkos syscall_entry_openat: { cpu_id = 3 }, { procname = "do-pagefault-op", vpid = 31576, vtid = 31576 }, { dfd = -100, filename = "/tmp/blah2", flags = ( "O_RDWR" : container = 2 ), mode = ( <unknown> : container = 0 ) }</p>
<p>Notice how filename = "/lib/x86_64-linux-gnu/libc.so.6" appears twice in the bt2 output, where we would expect the empty string (as provided by bt1).</p>
<p>Tested with babeltrace2 commit c429f86d0.</p> Babeltrace - Bug #1278 (Feedback): "Graph failed to complete successfully" errorhttps://bugs.lttng.org/issues/12782020-08-06T07:28:37ZSeongab Kim
<p>Hi,</p>
<p>I have a trace which babeltrace shows the error as below, but I can open it with Trace Compass without the issue.</p>
<pre>
08-06 07:22:48.227 28777 28777 E PLUGIN/FLT.UTILS.MUXER muxer_msg_iter_do_next_one@muxer.c:1081 [muxer] Youngest upstream message iterator wrapper's timestamp is less than muxer's message iterator's last returned timestamp: muxer-msg-iter-addr=0x18f2ff0, ts=1596631386358365554, last-returned-ts=1596631386358599346
08-06 07:22:48.227 28777 28777 E PLUGIN/FLT.UTILS.MUXER muxer_msg_iter_next@muxer.c:1415 [muxer] Cannot get next message: comp-addr=0x18f1d10, muxer-comp-addr=0x18f2400, muxer-msg-iter-addr=0x18f2ff0, msg-iter-addr=0x18f2e80, status=ERROR
08-06 07:22:48.227 28777 28777 W LIB/MSG-ITER bt_message_iterator_next@iterator.c:864 Component input port message iterator's "next" method failed: iter-addr=0x18f2e80, iter-upstream-comp-name="muxer", iter-upstream-comp-log-level=WARNING, iter-upstream-comp-class-type=FILTER, iter-upstream-comp-class-name="muxer", iter-upstream-comp-class-partial-descr="Sort messages from multiple inpu", iter-upstream-port-type=OUTPUT, iter-upstream-port-name="out", status=ERROR
08-06 07:22:48.227 28777 28777 W LIB/GRAPH consume_graph_sink@graph.c:473 Component's "consume" method failed: status=ERROR, comp-addr=0x18f2610, comp-name="pretty", comp-log-level=WARNING, comp-class-type=SINK, comp-class-name="pretty", comp-class-partial-descr="Pretty-print messages (`text` fo", comp-class-is-frozen=0, comp-class-so-handle-addr=0x186def0, comp-class-so-handle-path="/usr/lib/x86_64-linux-gnu/babeltrace2/plugins/babeltrace-plugin-text.so", comp-input-port-count=1, comp-output-port-count=0
08-06 07:22:48.227 28777 28777 E CLI cmd_run@babeltrace2.c:2548 Graph failed to complete successfully
ERROR: [Babeltrace CLI] (babeltrace2.c:2548)
Graph failed to complete successfully
CAUSED BY [libbabeltrace2] (graph.c:473)
Component's "consume" method failed: status=ERROR, comp-addr=0x18f2610,
comp-name="pretty", comp-log-level=WARNING, comp-class-type=SINK,
comp-class-name="pretty", comp-class-partial-descr="Pretty-print messages
(`text` fo", comp-class-is-frozen=0, comp-class-so-handle-addr=0x186def0,
comp-class-so-handle-path="/usr/lib/x86_64-linux-gnu/babeltrace2/plugins/babeltrace-plugin-text.so",
comp-input-port-count=1, comp-output-port-count=0
CAUSED BY [libbabeltrace2] (iterator.c:864)
Component input port message iterator's "next" method failed:
iter-addr=0x18f2e80, iter-upstream-comp-name="muxer",
iter-upstream-comp-log-level=WARNING, iter-upstream-comp-class-type=FILTER,
iter-upstream-comp-class-name="muxer",
iter-upstream-comp-class-partial-descr="Sort messages from multiple inpu",
iter-upstream-port-type=OUTPUT, iter-upstream-port-name="out", status=ERROR
CAUSED BY [muxer: 'filter.utils.muxer'] (muxer.c:1081)
Youngest upstream message iterator wrapper's timestamp is less than muxer's
message iterator's last returned timestamp: muxer-msg-iter-addr=0x18f2ff0,
ts=1596631386358365554, last-returned-ts=1596631386358599346
</pre>
<p>I'm using below version.</p>
<pre>
Babeltrace 2.0.4 "Amqui"
Amqui (/_mkwi_/) is a town in eastern Qu_bec, Canada, at the base of the Gasp_ peninsula in Bas-Saint-Laurent. Located at the confluence of the Humqui and Matap_dia Rivers, its proximity to
woodlands makes it a great destination for outdoor activities such as camping, hiking, and mountain biking.
</pre>
<p>Please let me know if you need a run with additional arguments.</p> Babeltrace - Bug #1277 (Confirmed): The `ctf` plugin does not support a negative TSDL clock class...https://bugs.lttng.org/issues/12772020-07-23T14:08:36ZSeongab Kim
<p>Hi,</p>
<p>I have a trace which cannot be opened by babeltrace as below, but I can open it with Trace Compass.</p>
<pre>
skim@d54030999178:/mnt/ssd/work/skim/traces$ babeltrace2 ./kernel/
</pre>
<pre>
07-22 07:49:20.099 5264 5264 E PLUGIN/CTF/META/IR-VISITOR get_unary_unsigned@visitor-generate-ir.c:800 [auto-disc-source-ctf-fs] At line 40 in metadata stream: Invalid constant unsigned integer.
07-22 07:49:20.099 5264 5264 E PLUGIN/CTF/META/IR-VISITOR visit_clock_decl_entry@visitor-generate-ir.c:4357 [auto-disc-source-ctf-fs] At line 40 in metadata stream: Unexpected unary expression for clock class's `offset` attribute.
07-22 07:49:20.099 5264 5264 E PLUGIN/CTF/META/IR-VISITOR visit_clock_decl@visitor-generate-ir.c:4532 [auto-disc-source-ctf-fs] At line 40 in metadata stream: Cannot visit clock class's entry: ret=-22
07-22 07:49:20.099 5264 5264 E PLUGIN/CTF/META/IR-VISITOR ctf_visitor_generate_ir_visit_node@visitor-generate-ir.c:4775 [auto-disc-source-ctf-fs] At line 41 in metadata stream: Cannot visit clock class: ret=-22
07-22 07:49:20.099 5264 5264 E PLUGIN/CTF/META/DECODER ctf_metadata_decoder_append_content@decoder.c:337 [auto-disc-source-ctf-fs] Failed to visit AST node to create CTF IR objects: mdec-addr=0x22a0d90, ret=-22
07-22 07:49:20.099 5264 5264 E PLUGIN/SRC.CTF.FS/META ctf_fs_metadata_set_trace_class@metadata.c:128 [auto-disc-source-ctf-fs] Cannot update metadata decoder's content.
07-22 07:49:20.122 5264 5264 E PLUGIN/SRC.CTF.FS ctf_fs_component_create_ctf_fs_trace_one_path@fs.c:1206 [auto-disc-source-ctf-fs] Cannot create trace for `/mnt/ssd/work/skim/traces/kernel`.
07-22 07:49:20.123 5264 5264 W LIB/GRAPH add_component_with_init_method_data@graph.c:977 Component initialization method failed: status=ERROR, comp-addr=0x22a68d0, comp-name="auto-disc-source-ctf-fs", comp-log-level=WARNING, comp-class-type=SOURCE, comp-class-name="fs", comp-class-partial-descr="Read CTF traces from the file sy", comp-class-is-frozen=0, comp-class-so-handle-addr=0x22b0de0, comp-class-so-handle-path="/usr/lib/x86_64-linux-gnu/babeltrace2/plugins/babeltrace-plugin-ctf.so", comp-input-port-count=0, comp-output-port-count=0
07-22 07:49:20.123 5264 5264 E CLI cmd_run_ctx_create_components_from_config_components@babeltrace2.c:2301 Cannot create component: plugin-name="ctf", comp-cls-name="fs", comp-cls-type=1, comp-name="auto-disc-source-ctf-fs"
07-22 07:49:20.123 5264 5264 E CLI cmd_run@babeltrace2.c:2480 Cannot create components.
ERROR: [Babeltrace CLI] (babeltrace2.c:2480)
Cannot create components.
CAUSED BY [Babeltrace CLI] (babeltrace2.c:2301)
Cannot create component: plugin-name="ctf", comp-cls-name="fs", comp-cls-type=1, comp-name="auto-disc-source-ctf-fs"
CAUSED BY [libbabeltrace2] (graph.c:977)
Component initialization method failed: status=ERROR, comp-addr=0x22a68d0, comp-name="auto-disc-source-ctf-fs", comp-log-level=WARNING,
comp-class-type=SOURCE, comp-class-name="fs", comp-class-partial-descr="Read CTF traces from the file sy", comp-class-is-frozen=0,
comp-class-so-handle-addr=0x22b0de0, comp-class-so-handle-path="/usr/lib/x86_64-linux-gnu/babeltrace2/plugins/babeltrace-plugin-ctf.so",
comp-input-port-count=0, comp-output-port-count=0 CAUSED BY [auto-disc-source-ctf-fs: 'source.ctf.fs'] (fs.c:1206)
Cannot create trace for `/mnt/ssd/work/skim/traces/kernel`.
</pre>
<p>I'm using below version.</p>
<pre>
skim@d54030999178:~/work/tmp$ babeltrace2 -V
Babeltrace 2.0.4 "Amqui"
Amqui (/_mkwi_/) is a town in eastern Qu_bec, Canada, at the base of the Gasp_ peninsula in Bas-Saint-Laurent. Located at the confluence of the Humqui and Matap_dia Rivers, its proximity to woodlands makes it a great destination for outdoor activities such as camping, hiking, and mountain biking.
</pre>
<p>Here is the test result which Philippe Proulx requested.</p>
<pre>
skim@d54030999178:~/ssd_work/traces$ babeltrace2 -o ctf-metadata ./kernel | grep -A10 '^clock {'
</pre>
<pre>
clock {
name = "monotonic";
uuid = "e00bcef2-1ef1-4f02-a241-8561834511fd";
description = "Monotonic Clock";
freq = 1000000000; /* Frequency, in Hz */
/* clock value offset from Epoch is: offset * (1/freq) */
offset = -48;
};
</pre> Babeltrace - Bug #1234 (Feedback): src.text.dmesg: some kernel ring buffer lines can be wrongly s...https://bugs.lttng.org/issues/12342020-02-17T21:54:00ZPhilippe Proulxeeppeliteloop@gmail.com
<p>The lines of the <code>dmesg</code> command start with a time. The lines are supposed to be in order of time, but some of them can be at the wrong place.</p>
<p><code>flt.utils.muxer</code> does not like this and complains that event messages are not sorted by their default clock snapshot value.</p>
<p>It is, in fact, a <code>src.text.dmesg</code> bug because a message iterator must emit messages in order of time.</p>
<p>If the input is a file, one solution would be to sort the lines first (if not too large), and then emit the messages in this order.</p>
<p>We could also, in all scenarios, skip the lines with a time that is before the last event message's time and warn accordingly.</p> Babeltrace - Bug #1225 (On pause): src.ctf.lttng-live: `sessions` query error reportinghttps://bugs.lttng.org/issues/12252020-02-17T21:07:37ZFrancis Deslauriersfrancis.deslauriers@efficios.com
<p>The right format to query the list of sessions is:<br /><pre>
babeltrace2 query -p 'url="net://127.0.0.1"' src.ctf.lttng-live sessions
</pre></p>
<p>When adding a `/` at the end of the URL (by mistake maybe) you get the following error:<br /><pre>
10-23 10:11:25.193 2096 2096 E PLUGIN/SRC.CTF.LTTNG-LIVE/VIEWER parse_url@viewer-connection.c:127 [lttng-live] Invalid LTTng live URL format: Expecting `/host/` after hostname or port
10-23 10:11:25.193 2096 2096 E PLUGIN/SRC.CTF.LTTNG-LIVE/VIEWER lttng_live_connect_viewer@viewer-connection.c:253 [lttng-live] Failed to parse URL
10-23 10:11:25.193 2096 2096 E PLUGIN/SRC.CTF.LTTNG-LIVE/VIEWER live_viewer_connection_create@viewer-connection.c:1629 [lttng-live] Failure to establish connection: url="net://127.0.0.1/"
10-23 10:11:25.193 2096 2096 E PLUGIN/SRC.CTF.LTTNG-LIVE lttng_live_query_list_sessions@lttng-live.c:1589 [lttng-live] Failed to create viewer connection
10-23 10:11:25.193 2096 2096 W LIB/QUERY-EXECUTOR bt_query_executor_query@query-executor.c:246 Component class's "query" method failed: query-exec-addr=0x5625255fd7a0, cc-addr=0x5625255f80a0, cc-type=SOURCE, cc-name="lttng-live", cc-partial-descr="Connect to an LTTng relay daemon", cc-is-frozen=0, cc-so-handle-addr=0x5625255f7270, cc-so-handle-path="/usr/local/lib/babeltrace2/plugins/babeltrace-plugin-ctf.so", object="sessions", params-addr=0x5625255e4540, params-type=MAP, params-element-count=1, log-level=WARNING
10-23 10:11:25.193 2096 2096 E CLI cmd_query@babeltrace2.c:727 Failed to query component class: unknown error: plugin-name="ctf", comp-cls-name="lttng-live", comp-cls-type=1 object="sessions"
ERROR: [Babeltrace CLI] (babeltrace2.c:727)
Failed to query component class: unknown error: plugin-name="ctf", comp-cls-name="lttng-live", comp-cls-type=1
object="sessions"
CAUSED BY [Babeltrace library] (query-executor.c:246)
Component class's "query" method failed: query-exec-addr=0x5625255fd7a0, cc-addr=0x5625255f80a0, cc-type=SOURCE,
cc-name="lttng-live", cc-partial-descr="Connect to an LTTng relay daemon", cc-is-frozen=0,
cc-so-handle-addr=0x5625255f7270, cc-so-handle-path="/usr/local/lib/babeltrace2/plugins/babeltrace-plugin-ctf.so",
object="sessions", params-addr=0x5625255e4540, params-type=MAP, params-element-count=1, log-level=WARNING
CAUSED BY ['source.ctf.lttng-live'] (lttng-live.c:1589)
Failed to create viewer connection
CAUSED BY ['source.ctf.lttng-live'] (viewer-connection.c:1629)
Failure to establish connection: url="net://127.0.0.1/"
CAUSED BY ['source.ctf.lttng-live'] (viewer-connection.c:253)
Failed to parse URL
CAUSED BY ['source.ctf.lttng-live'] (viewer-connection.c:127)
Invalid LTTng live URL format: Expecting `/host/` after hostname or port
</pre><br />Suggesting to add the `/host/` part of the URL as if we were trying to connect to a session.<br />When in fact, since I am in a query, I would want it to be suggesting me to remove the extra `/` if anything.</p> Babeltrace - Bug #1223 (Feedback): Check for cmp and diff in configurehttps://bugs.lttng.org/issues/12232020-02-17T21:03:26ZSimon Marchisimon.marchi@polymtl.ca
<p>Seen somewhere in the configure output of babeltrace on a fresh centos 8 container:</p>
<pre>
checking for a working dd... ./configure: line 9826: cmp: command not found
checking if gcc supports -fno-rtti -fno-exceptions... ./configure: line 11790: diff: command not found
</pre>
<p>The configure keeps going, I think the consequence may simply be that the results of these checks are inaccurate.</p>
<p>For correctness, if these tools (cmd and diff) are used, there should be something that checks that they exist before using them.</p> Babeltrace - Bug #1168 (Feedback): CTF for a user-plugged clock assumes that "offset" is unsigned...https://bugs.lttng.org/issues/11682018-05-31T21:52:00ZVlad Roubtsov
<p>Hi,</p>
<p>I need to switch LTTng timestamp source to CLOCK_REALTIME from CLOCK_MONOTONIC in order to correlate with hardware-generated timestamps in a NIC. My initial attempt was easy enough to get going as a clock plugin:</p>
<pre><code class="cpp syntaxhl" data-language="cpp"><span class="k">static</span> <span class="kt">uint64_t</span>
<span class="nf">my_clock_time</span> <span class="p">()</span>
<span class="p">{</span>
<span class="k">struct</span> <span class="nc">timespec</span> <span class="n">t</span><span class="p">;</span>
<span class="n">clock_gettime</span> <span class="p">(</span><span class="n">CLOCK_REALTIME</span><span class="p">,</span> <span class="o">&</span> <span class="n">t</span><span class="p">);</span>
<span class="k">return</span> <span class="p">(</span><span class="n">t</span><span class="p">.</span><span class="n">tv_sec</span> <span class="o">*</span> <span class="mi">1000000000UL</span> <span class="o">+</span> <span class="n">t</span><span class="p">.</span><span class="n">tv_nsec</span><span class="p">);</span>
<span class="p">}</span>
<span class="k">static</span> <span class="kt">uint64_t</span>
<span class="nf">my_clock_freq</span> <span class="p">()</span>
<span class="p">{</span>
<span class="k">return</span> <span class="mi">1000000000UL</span><span class="p">;</span>
<span class="p">}</span>
</code></pre>
<p>(the rest follows the "clock-override" example). However, this results in sporadic errors opening the trace later via babeltrace:<br /><pre>
[error] ctf_clock_declaration_visit: unexpected unary expression for clock offset
[error] ctf_visitor_construct_metadata: clock declaration error
[error] Error in CTF metadata constructor -22
[warning] Unable to open trace metadata for path "/.../ust/pid/...-115227-20180601-062437".
[warning] [Context] Cannot open_trace of format ctf at path /...-115227-20180601-062437.
</pre></p>
<p>It appears that this happens when LTTng calculates the clock's "epoch offset" (which in theory should be 0 above) and it comes out as a small negative number. To reproduce this <em>every time</em>, try shifting the <code>my_clock_value()</code> result:</p>
<pre><code class="cpp syntaxhl" data-language="cpp"><span class="k">static</span> <span class="kt">uint64_t</span>
<span class="nf">my_clock_time</span> <span class="p">()</span>
<span class="p">{</span>
<span class="k">struct</span> <span class="nc">timespec</span> <span class="n">t</span><span class="p">;</span>
<span class="n">clock_gettime</span> <span class="p">(</span><span class="n">CLOCK_REALTIME</span><span class="p">,</span> <span class="o">&</span> <span class="n">t</span><span class="p">);</span>
<span class="k">return</span> <span class="p">(</span><span class="n">t</span><span class="p">.</span><span class="n">tv_sec</span> <span class="o">*</span> <span class="mi">1000000000UL</span> <span class="o">+</span> <span class="n">t</span><span class="p">.</span><span class="n">tv_nsec</span> <span class="o">+</span> <span class="mi">1000</span><span class="p">);</span>
<span class="p">}</span>
</code></pre>
<p>Peeking inside the persisted "metadata" you will see something like this:<br /><pre>
>hexdump -C /...-115227-20180601-062437/metadata | less
...
00000440 4c 54 49 4d 45 22 3b 0a 09 66 72 65 71 20 3d 20 |LTIME";..freq = |
00000450 31 30 30 30 30 30 30 30 30 30 3b 20 2f 2a 20 46 |1000000000; /* F|
00000460 72 65 71 75 65 6e 63 79 2c 20 69 6e 20 48 7a 20 |requency, in Hz |
00000470 2a 2f 0a 09 2f 2a 20 63 6c 6f 63 6b 20 76 61 6c |*/../* clock val|
00000480 75 65 20 6f 66 66 73 65 74 20 66 72 6f 6d 20 45 |ue offset from E|
00000490 70 6f 63 68 20 69 73 3a 20 6f 66 66 73 65 74 20 |poch is: offset |
000004a0 2a 20 28 31 2f 66 72 65 71 29 20 2a 2f 0a 09 6f |* (1/freq) */..o|
000004b0 66 66 73 65 74 20 3d 20 2d 31 30 30 31 3b 0a 7d |ffset = -1001;.}| <- negative value stored as "signed = false" int?
000004c0 3b 0a 0a 74 79 70 65 61 6c 69 61 73 20 69 6e 74 |;..typealias int|
000004d0 65 67 65 72 20 7b 0a 09 73 69 7a 65 20 3d 20 32 |eger {..size = 2|
000004e0 37 3b 20 61 6c 69 67 6e 20 3d 20 31 3b 20 73 69 |7; align = 1; si|
000004f0 67 6e 65 64 20 3d 20 66 61 6c 73 65 3b 0a 09 6d |gned = false;..m|
</pre></p>
<p>My env details (both lttng and babeltrace were built from stable sources):<br /><pre>
>lttng --version
lttng (LTTng Trace Control) 2.10.4 - KeKriek
>lttng-sessiond --version
2.10.4
>babeltrace --version
BabelTrace Trace Viewer and Converter 1.5.5
>uname -a
Linux ... 3.10.0-693.11.6.el7.x86_64 #1 SMP Thu Jan 4 01:06:37 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
>cat /etc/system-release
CentOS Linux release 7.4.1708 (Core)
>nproc
16
</pre></p>