Project

General

Profile

Actions

Bug #1221

open

Babeltrace 2 sometimes fail on live trace with lttng-clear feature

Added by Mathieu Desnoyers almost 5 years ago. Updated almost 5 years ago.

Status:
New
Priority:
Normal
Assignee:
-
Category:
src.ctf.lttng-live
Start date:
02/17/2020
Due date:
% Done:

0%

Estimated time:

Description

Babeltrace 2 sometimes fail on live trace with lttng-clear feature

This may happen in a scenario where per-pid buffers are used, an application has just quit, and babeltrace 2 observes a stream in make_viewer_streams, but then fails to open the associated index or data file on the first get_next_index because it has been unlinked by clear.

The babeltrace output is:

12-04 14:01:48.455 11884 11884 E PLUGIN/CTF/MSG-ITER create_msg_stream_end@msg-iter.c:2464 [lttng-live] Cannot create stream for stream message: notit-addr=0x55b89f957980
12-04 14:01:48.455 11884 11884 W LIB/MSG-ITER bt_self_component_port_input_message_iterator_next@iterator.c:906 Component input port message iterator's "next" method failed: iter-addr=0x55b89f93f510, iter-upstream-comp-name="lttng-live", iter-upstream-comp-log-level=WARNING, iter-upstream-comp-class-type=SOURCE, iter-upstream-comp-class-name="lttng-live", iter-upstream-comp-class-partial-descr="Connect to an LTTng relay daemon", iter-upstream-port-type=OUTPUT, iter-upstream-port-name="out", status=ERROR
12-04 14:01:48.455 11884 11884 E PLUGIN/FLT.UTILS.MUXER muxer_upstream_msg_iter_next@muxer.c:444 [muxer] Error or unsupported status code: status-code=-1
12-04 14:01:48.455 11884 11884 E PLUGIN/FLT.UTILS.MUXER validate_muxer_upstream_msg_iters@muxer.c:975 [muxer] Cannot validate muxer's upstream message iterator wrapper: muxer-msg-iter-addr=0x55b89f950950, muxer-upstream-msg-iter-wrap-addr=0x55b89f9415d0
12-04 14:01:48.455 11884 11884 E PLUGIN/FLT.UTILS.MUXER muxer_msg_iter_next@muxer.c:1371 [muxer] Cannot get next message: comp-addr=0x55b89f93ebc0, muxer-comp-addr=0x55b89f93ec40, muxer-msg-iter-addr=0x55b89f950950, msg-iter-addr=0x55b89f93f3a0, status=ERROR
12-04 14:01:48.455 11884 11884 W LIB/MSG-ITER bt_self_component_port_input_message_iterator_next@iterator.c:906 Component input port message iterator's "next" method failed: iter-addr=0x55b89f93f3a0, 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
12-04 14:01:48.455 11884 11884 W LIB/GRAPH consume_graph_sink@graph.c:596 Component's "consume" method failed: status=ERROR, comp-addr=0x55b89f93ed30, 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=0x55b89f94c740, comp-class-so-handle-path="/usr/local/lib/babeltrace2/plugins/babeltrace-plugin-text.so", comp-input-port-count=1, comp-output-port-count=0
12-04 14:01:48.456 11884 11884 E CLI cmd_run@babeltrace2.c:2574 Graph failed to complete successfully

ERROR:    [Babeltrace CLI] (babeltrace2.c:2574)
  Graph failed to complete successfully
CAUSED BY [Babeltrace library] (graph.c:596)
  Component's "consume" method failed: status=ERROR, comp-addr=0x55b89f93ed30,
  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=0x55b89f94c740,
  comp-class-so-handle-path="/usr/local/lib/babeltrace2/plugins/babeltrace-plugin-text.so",
  comp-input-port-count=1, comp-output-port-count=0
CAUSED BY [Babeltrace library] (iterator.c:906)
  Component input port message iterator's "next" method failed:
  iter-addr=0x55b89f93f3a0, 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 [Babeltrace library] (iterator.c:906)
  Component input port message iterator's "next" method failed:
  iter-addr=0x55b89f93f510, iter-upstream-comp-name="lttng-live",
  iter-upstream-comp-log-level=WARNING, iter-upstream-comp-class-type=SOURCE,
  iter-upstream-comp-class-name="lttng-live",
  iter-upstream-comp-class-partial-descr="Connect to an LTTng relay daemon",
  iter-upstream-port-type=OUTPUT, iter-upstream-port-name="out", status=ERROR

notit->stream is expected not to be NULL when reaching the state STATE_EMIT_MSG_STREAM_END, but if no packet was received, it is indeed still NULL, because it is the packet header being read that moves to the STATE_CHECK_EMIT_MSG_STREAM_BEGINNING state (after_packet_context_state()).

Actions #1

Updated by Jonathan Rajotte Julien almost 5 years ago

updated error from latest bt2:

12-04 14:32:53.049 15489 15489 E PLUGIN/CTF/MSG-ITER create_msg_stream_end@msg-iter.c:2474 [lttng-live] Cannot create stream end message because stream is NULL: msg-it-addr=0x561b56c5ce00
12-04 14:32:53.050 15489 15489 E PLUGIN/SRC.CTF.LTTNG-LIVE lttng_live_iterator_close_stream@lttng-live.c:873 [lttng-live] Error getting the next message from CTF message iterator
12-04 14:32:53.050 15489 15489 E PLUGIN/SRC.CTF.LTTNG-LIVE lttng_live_msg_iter_next@lttng-live.c:1518 [lttng-live] Error preparing the next batch of messages: live-iter-status=LTTNG_LIVE_ITERATOR_STATUS_ERROR
12-04 14:32:53.050 15489 15489 W LIB/MSG-ITER bt_self_component_port_input_message_iterator_next@iterator.c:928 Component input port message iterator's "next" method failed: iter-addr=0x561b56c58510, iter-upstream-comp-name="lttng-live", iter-upstream-comp-log-level=WARNING, iter-upstream-comp-class-type=SOURCE, iter-upstream-comp-class-name="lttng-live", iter-upstream-comp-class-partial-descr="Connect to an LTTng relay daemon", iter-upstream-port-type=OUTPUT, iter-upstream-port-name="out", status=ERROR
12-04 14:32:53.050 15489 15489 E PLUGIN/FLT.UTILS.MUXER muxer_upstream_msg_iter_next@muxer.c:454 [muxer] Upstream iterator's next method returned an error: status=ERROR
12-04 14:32:53.050 15489 15489 E PLUGIN/FLT.UTILS.MUXER validate_muxer_upstream_msg_iters@muxer.c:991 [muxer] Cannot validate muxer's upstream message iterator wrapper: muxer-msg-iter-addr=0x561b56c69950, muxer-upstream-msg-iter-wrap-addr=0x561b56c5a660
12-04 14:32:53.050 15489 15489 E PLUGIN/FLT.UTILS.MUXER muxer_msg_iter_next@muxer.c:1414 [muxer] Cannot get next message: comp-addr=0x561b56c57bc0, muxer-comp-addr=0x561b56c57c40, muxer-msg-iter-addr=0x561b56c69950, msg-iter-addr=0x561b56c583a0, status=ERROR
12-04 14:32:53.050 15489 15489 W LIB/MSG-ITER bt_self_component_port_input_message_iterator_next@iterator.c:928 Component input port message iterator's "next" method failed: iter-addr=0x561b56c583a0, 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
12-04 14:32:53.050 15489 15489 W LIB/GRAPH consume_graph_sink@graph.c:600 Component's "consume" method failed: status=ERROR, comp-addr=0x561b56c57d30, 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=0x561b56c65740, comp-class-so-handle-path="/usr/local/lib/babeltrace2/plugins/babeltrace-plugin-text.so", comp-input-port-count=1, comp-output-port-count=0
12-04 14:32:53.050 15489 15489 E CLI cmd_run@babeltrace2.c:2591 Graph failed to complete successfully

ERROR:    [Babeltrace CLI] (babeltrace2.c:2591)
  Graph failed to complete successfully
CAUSED BY [libbabeltrace2] (graph.c:600)
  Component's "consume" method failed: status=ERROR, comp-addr=0x561b56c57d30,
  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=0x561b56c65740,
  comp-class-so-handle-path="/usr/local/lib/babeltrace2/plugins/babeltrace-plugin-text.so",
  comp-input-port-count=1, comp-output-port-count=0
CAUSED BY [libbabeltrace2] (iterator.c:928)
  Component input port message iterator's "next" method failed:
  iter-addr=0x561b56c583a0, 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:991)
  Cannot validate muxer's upstream message iterator wrapper:
  muxer-msg-iter-addr=0x561b56c69950,
  muxer-upstream-msg-iter-wrap-addr=0x561b56c5a660
CAUSED BY [muxer: 'filter.utils.muxer'] (muxer.c:454)
  Upstream iterator's next method returned an error: status=ERROR
CAUSED BY [libbabeltrace2] (iterator.c:928)
  Component input port message iterator's "next" method failed:
  iter-addr=0x561b56c58510, iter-upstream-comp-name="lttng-live",
  iter-upstream-comp-log-level=WARNING, iter-upstream-comp-class-type=SOURCE,
  iter-upstream-comp-class-name="lttng-live",
  iter-upstream-comp-class-partial-descr="Connect to an LTTng relay daemon",
  iter-upstream-port-type=OUTPUT, iter-upstream-port-name="out", status=ERROR
CAUSED BY [lttng-live: 'source.ctf.lttng-live'] (lttng-live.c:1518)
  Error preparing the next batch of messages:
  live-iter-status=LTTNG_LIVE_ITERATOR_STATUS_ERROR
CAUSED BY [lttng-live: 'source.ctf.lttng-live'] (lttng-live.c:873)
  Error getting the next message from CTF message iterator
CAUSED BY [lttng-live: 'source.ctf.lttng-live'] (msg-iter.c:2474)
  Cannot create stream end message because stream is NULL:
  msg-it-addr=0x561b56c5ce00
Actions #2

Updated by Jonathan Rajotte Julien almost 5 years ago

  • Category set to src.ctf.lttng-live
Actions #3

Updated by Jonathan Rajotte Julien almost 5 years ago

  • Author changed from 215 to 9
Actions

Also available in: Atom PDF