sink.ctf.fs: append error causes where relevant

The `sink.ctf.fs` component class doesn't append error causes when it
encounters errors.  This makes the error reporting very vague.  For
example, both when the user fails to pass the required `path` parameter
and when they pass a path to a directory they don't have write
permissions on, they get:

    ERROR:    [Babeltrace CLI] (/home/simark/src/babeltrace/src/cli/babeltrace2.c:2462)
      Cannot create components.
    CAUSED BY [Babeltrace CLI] (/home/simark/src/babeltrace/src/cli/babeltrace2.c:2277)
      Cannot create component: plugin-name="ctf", comp-cls-name="fs", comp-cls-type=4, comp-name="sink.ctf.fs"
    CAUSED BY [libbabeltrace2] (/home/simark/src/babeltrace/src/lib/graph/graph.c:1055)
      Component initialization method failed: status=ERROR, comp-addr=0x60c000011d40, comp-name="sink.ctf.fs", comp-log-level=WARNING, comp-class-type=SINK, comp-class-name="fs",
      comp-class-partial-descr="Write CTF traces to the file sys", comp-class-is-frozen=1, comp-class-so-handle-addr=0x607000000100,
      comp-class-so-handle-path="/home/simark/build/babeltrace/src/plugins/ctf/babeltrace-plugin-ctf.la", comp-input-port-count=0, comp-output-port-count=0

Add calls to append error causes where relevant.  It becomes much easier
to distinguish the errors:

    ERROR:    [Babeltrace CLI] (/home/simark/src/babeltrace/src/cli/babeltrace2.c:2462)
      Cannot create components.
    CAUSED BY [Babeltrace CLI] (/home/simark/src/babeltrace/src/cli/babeltrace2.c:2277)
      Cannot create component: plugin-name="ctf", comp-cls-name="fs", comp-cls-type=4, comp-name="sink.ctf.fs"
    CAUSED BY [libbabeltrace2] (/home/simark/src/babeltrace/src/lib/graph/graph.c:1055)
      Component initialization method failed: status=ERROR, comp-addr=0x60c000011d40, comp-name="sink.ctf.fs", comp-log-level=WARNING, comp-class-type=SINK, comp-class-name="fs",
      comp-class-partial-descr="Write CTF traces to the file sys", comp-class-is-frozen=1, comp-class-so-handle-addr=0x607000000100,
      comp-class-so-handle-path="/home/simark/build/babeltrace/src/plugins/ctf/babeltrace-plugin-ctf.la", comp-input-port-count=0, comp-output-port-count=0
    CAUSED BY [sink.ctf.fs: 'sink.ctf.fs'] (/home/simark/src/babeltrace/src/plugins/ctf/fs-sink/fs-sink.c:74)
      Error validating parameters: missing mandatory entry `path`

and

    ERROR:    [Babeltrace CLI] (/home/simark/src/babeltrace/src/cli/babeltrace2.c:2462)
      Cannot create components.
    CAUSED BY [Babeltrace CLI] (/home/simark/src/babeltrace/src/cli/babeltrace2.c:2277)
      Cannot create component: plugin-name="ctf", comp-cls-name="fs", comp-cls-type=4, comp-name="sink.ctf.fs"
    CAUSED BY [libbabeltrace2] (/home/simark/src/babeltrace/src/lib/graph/graph.c:1055)
      Component initialization method failed: status=ERROR, comp-addr=0x60c000011e00, comp-name="sink.ctf.fs", comp-log-level=WARNING, comp-class-type=SINK, comp-class-name="fs",
      comp-class-partial-descr="Write CTF traces to the file sys", comp-class-is-frozen=1, comp-class-so-handle-addr=0x607000000100,
      comp-class-so-handle-path="/home/simark/build/babeltrace/src/plugins/ctf/babeltrace-plugin-ctf.la", comp-input-port-count=0, comp-output-port-count=0
    CAUSED BY [sink.ctf.fs: 'sink.ctf.fs'] (/home/simark/src/babeltrace/src/plugins/ctf/fs-sink/fs-sink.c:40)
      Cannot create directories for output directory: Permission denied: output-dir-path="/tmp/pouet/yo"

Change-Id: I384e88a1d2629ac75495518c8bce2a2cba2f9741
Signed-off-by: Simon Marchi <simon.marchi@efficios.com>
Reviewed-on: https://review.lttng.org/c/babeltrace/+/3907
Reviewed-by: Philippe Proulx <eeppeliteloop@gmail.com>
Tested-by: jenkins <jenkins@lttng.org>

diff --git a/src/plugins/ctf/fs-sink/fs-sink.c b/src/plugins/ctf/fs-sink/fs-sink.c
index 0672890a8d4ad4fd63611a9497c51d8c96e8b1ee..4b077507b7a4bd9f71a2c99d1f63a163185b9df8 100644 (file)
--- a/src/plugins/ctf/fs-sink/fs-sink.c
+++ b/src/plugins/ctf/fs-sink/fs-sink.c
@@ -37,7 +37,7 @@ bt_component_class_initialize_method_status ensure_output_dir_exists(
 
        ret = g_mkdir_with_parents(fs_sink->output_dir_path->str, 0755);
        if (ret) {
-               BT_COMP_LOGE_ERRNO(
+               BT_COMP_LOGE_APPEND_CAUSE_ERRNO(fs_sink->self_comp,
                        "Cannot create directories for output directory",
                        ": output-dir-path=\"%s\"",
                        fs_sink->output_dir_path->str);
@@ -71,6 +71,8 @@ configure_component(struct fs_sink_comp *fs_sink, const bt_value *params)
                fs_sink_params_descr, &validation_error);
        if (validation_status == BT_PARAM_VALIDATION_STATUS_VALIDATION_ERROR) {
                status = BT_COMPONENT_CLASS_INITIALIZE_METHOD_STATUS_ERROR;
+               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                       "%s", validation_error);
                goto end;
        } else if (validation_status == BT_PARAM_VALIDATION_STATUS_MEMORY_ERROR) {
                status = BT_COMPONENT_CLASS_INITIALIZE_METHOD_STATUS_MEMORY_ERROR;
@@ -146,8 +148,7 @@ bt_component_class_initialize_method_status ctf_fs_sink_init(
                const bt_value *params,
                void *init_method_data)
 {
-       bt_component_class_initialize_method_status status =
-               BT_COMPONENT_CLASS_INITIALIZE_METHOD_STATUS_OK;
+       bt_component_class_initialize_method_status status;
        bt_self_component_add_port_status add_port_status;
        struct fs_sink_comp *fs_sink = NULL;
        bt_self_component *self_comp =
@@ -159,6 +160,8 @@ bt_component_class_initialize_method_status ctf_fs_sink_init(
        if (!fs_sink) {
                BT_COMP_LOG_CUR_LVL(BT_LOG_ERROR, log_level, self_comp,
                        "Failed to allocate one CTF FS sink structure.");
+               BT_CURRENT_THREAD_ERROR_APPEND_CAUSE_FROM_COMPONENT(
+                       self_comp, "Failed to allocate one CTF FS sink structure.");
                status = BT_COMPONENT_CLASS_INITIALIZE_METHOD_STATUS_MEMORY_ERROR;
                goto end;
        }
@@ -175,8 +178,9 @@ bt_component_class_initialize_method_status ctf_fs_sink_init(
        if (fs_sink->assume_single_trace &&
                        g_file_test(fs_sink->output_dir_path->str,
                                G_FILE_TEST_EXISTS)) {
-               BT_COMP_LOGE("Single trace mode, but output path exists: "
-                       "output-path=\"%s\"", fs_sink->output_dir_path->str);
+               BT_COMP_LOGE_APPEND_CAUSE(self_comp,
+                       "Single trace mode, but output path exists: output-path=\"%s\"",
+                       fs_sink->output_dir_path->str);
                status = BT_COMPONENT_CLASS_INITIALIZE_METHOD_STATUS_ERROR;
                goto end;
        }
@@ -190,22 +194,17 @@ bt_component_class_initialize_method_status ctf_fs_sink_init(
        fs_sink->traces = g_hash_table_new_full(g_direct_hash, g_direct_equal,
                NULL, (GDestroyNotify) fs_sink_trace_destroy);
        if (!fs_sink->traces) {
-               BT_COMP_LOGE_STR("Failed to allocate one GHashTable.");
+               BT_COMP_LOGE_APPEND_CAUSE(self_comp, "Failed to allocate one GHashTable.");
                status = BT_COMPONENT_CLASS_INITIALIZE_METHOD_STATUS_MEMORY_ERROR;
                goto end;
        }
 
        add_port_status = bt_self_component_sink_add_input_port(
                self_comp_sink, in_port_name, NULL, NULL);
-       switch (add_port_status) {
-       case BT_SELF_COMPONENT_ADD_PORT_STATUS_ERROR:
-               status = BT_COMPONENT_CLASS_INITIALIZE_METHOD_STATUS_ERROR;
+       if (add_port_status != BT_SELF_COMPONENT_ADD_PORT_STATUS_OK) {
+               status = (int) add_port_status;
+               BT_COMP_LOGE_APPEND_CAUSE(self_comp, "Failed to add input port.");
                goto end;
-       case BT_SELF_COMPONENT_ADD_PORT_STATUS_MEMORY_ERROR:
-               status = BT_COMPONENT_CLASS_INITIALIZE_METHOD_STATUS_MEMORY_ERROR;
-               goto end;
-       default:
-               break;
        }
 
        bt_self_component_set_data(self_comp, fs_sink);
@@ -230,7 +229,8 @@ struct fs_sink_stream *borrow_stream(struct fs_sink_comp *fs_sink,
        if (G_UNLIKELY(!trace)) {
                if (fs_sink->assume_single_trace &&
                                g_hash_table_size(fs_sink->traces) > 0) {
-                       BT_COMP_LOGE("Single trace mode, but getting more than one trace: "
+                       BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                               "Single trace mode, but getting more than one trace: "
                                "stream-name=\"%s\"",
                                bt_stream_get_name(ir_stream));
                        goto end;
@@ -269,6 +269,8 @@ bt_component_class_sink_consume_method_status handle_event_msg(
 
        stream = borrow_stream(fs_sink, ir_stream);
        if (G_UNLIKELY(!stream)) {
+               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                       "Failed to borrow stream.");
                status = BT_COMPONENT_CLASS_SINK_CONSUME_METHOD_STATUS_ERROR;
                goto end;
        }
@@ -276,6 +278,8 @@ bt_component_class_sink_consume_method_status handle_event_msg(
        ret = try_translate_event_class_trace_ir_to_ctf_ir(fs_sink,
                stream->sc, bt_event_borrow_class_const(ir_event), &ec);
        if (ret) {
+               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                       "Failed to translate event class to CTF IR.");
                status = BT_COMPONENT_CLASS_SINK_CONSUME_METHOD_STATUS_ERROR;
                goto end;
        }
@@ -307,6 +311,8 @@ bt_component_class_sink_consume_method_status handle_event_msg(
                         */
                        ret = fs_sink_stream_close_packet(stream, NULL);
                        if (ret) {
+                               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                                       "Failed to close packet.");
                                status = BT_COMPONENT_CLASS_SINK_CONSUME_METHOD_STATUS_ERROR;
                                goto end;
                        }
@@ -316,6 +322,8 @@ bt_component_class_sink_consume_method_status handle_event_msg(
                        /* Stream's packet is not currently opened: open it */
                        ret = fs_sink_stream_open_packet(stream, NULL, NULL);
                        if (ret) {
+                               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                                       "Failed to open packet.");
                                status = BT_COMPONENT_CLASS_SINK_CONSUME_METHOD_STATUS_ERROR;
                                goto end;
                        }
@@ -325,6 +333,8 @@ bt_component_class_sink_consume_method_status handle_event_msg(
        BT_ASSERT_DBG(stream->packet_state.is_open);
        ret = fs_sink_stream_write_event(stream, cs, ir_event, ec);
        if (G_UNLIKELY(ret)) {
+               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                       "Failed to write event.");
                status = BT_COMPONENT_CLASS_SINK_CONSUME_METHOD_STATUS_ERROR;
                goto end;
        }
@@ -348,6 +358,8 @@ bt_component_class_sink_consume_method_status handle_packet_beginning_msg(
 
        stream = borrow_stream(fs_sink, ir_stream);
        if (G_UNLIKELY(!stream)) {
+               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                       "Failed to borrow stream.");
                status = BT_COMPONENT_CLASS_SINK_CONSUME_METHOD_STATUS_ERROR;
                goto end;
        }
@@ -399,7 +411,8 @@ bt_component_class_sink_consume_method_status handle_packet_beginning_msg(
 
                if (stream->discarded_events_state.beginning_cs !=
                                expected_cs) {
-                       BT_COMP_LOGE("Incompatible discarded events message: "
+                       BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                               "Incompatible discarded events message: "
                                "unexpected beginning time: "
                                "beginning-cs-val=%" PRIu64 ", "
                                "expected-beginning-cs-val=%" PRIu64 ", "
@@ -449,7 +462,8 @@ bt_component_class_sink_consume_method_status handle_packet_beginning_msg(
                 * this case.
                 */
                if (stream->prev_packet_state.end_cs == UINT64_C(-1)) {
-                       BT_COMP_LOGE("Incompatible discarded packets message "
+                       BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                               "Incompatible discarded packets message "
                                "occurring before the stream's first packet: "
                                "stream-id=%" PRIu64 ", stream-name=\"%s\", "
                                "trace-name=\"%s\", path=\"%s/%s\"",
@@ -464,7 +478,8 @@ bt_component_class_sink_consume_method_status handle_packet_beginning_msg(
 
                if (stream->discarded_packets_state.beginning_cs !=
                                stream->prev_packet_state.end_cs) {
-                       BT_COMP_LOGE("Incompatible discarded packets message: "
+                       BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                               "Incompatible discarded packets message: "
                                "unexpected beginning time: "
                                "beginning-cs-val=%" PRIu64 ", "
                                "expected-beginning-cs-val=%" PRIu64 ", "
@@ -485,7 +500,8 @@ bt_component_class_sink_consume_method_status handle_packet_beginning_msg(
 
                if (stream->discarded_packets_state.end_cs !=
                                expected_end_cs) {
-                       BT_COMP_LOGE("Incompatible discarded packets message: "
+                       BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                               "Incompatible discarded packets message: "
                                "unexpected end time: "
                                "end-cs-val=%" PRIu64 ", "
                                "expected-end-cs-val=%" PRIu64 ", "
@@ -513,6 +529,8 @@ bt_component_class_sink_consume_method_status handle_packet_beginning_msg(
 
        ret = fs_sink_stream_open_packet(stream, cs, ir_packet);
        if (ret) {
+               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                       "Failed to open packet.");
                status = BT_COMPONENT_CLASS_SINK_CONSUME_METHOD_STATUS_ERROR;
                goto end;
        }
@@ -536,6 +554,8 @@ bt_component_class_sink_consume_method_status handle_packet_end_msg(
 
        stream = borrow_stream(fs_sink, ir_stream);
        if (G_UNLIKELY(!stream)) {
+               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                       "Failed to borrow stream.");
                status = BT_COMPONENT_CLASS_SINK_CONSUME_METHOD_STATUS_ERROR;
                goto end;
        }
@@ -575,7 +595,8 @@ bt_component_class_sink_consume_method_status handle_packet_end_msg(
                expected_cs = bt_clock_snapshot_get_value(cs);
 
                if (stream->discarded_events_state.end_cs != expected_cs) {
-                       BT_COMP_LOGE("Incompatible discarded events message: "
+                       BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                               "Incompatible discarded events message: "
                                "unexpected end time: "
                                "end-cs-val=%" PRIu64 ", "
                                "expected-end-cs-val=%" PRIu64 ", "
@@ -595,6 +616,8 @@ bt_component_class_sink_consume_method_status handle_packet_end_msg(
 
        ret = fs_sink_stream_close_packet(stream, cs);
        if (ret) {
+               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                       "Failed to close packet.");
                status = BT_COMPONENT_CLASS_SINK_CONSUME_METHOD_STATUS_ERROR;
                goto end;
        }
@@ -636,7 +659,8 @@ bt_component_class_sink_consume_method_status handle_stream_beginning_msg(
 
                if (!fs_sink->ignore_discarded_events &&
                                bt_stream_class_supports_discarded_events(ir_sc)) {
-                       BT_COMP_LOGE("Unsupported stream: "
+                       BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                               "Unsupported stream: "
                                "stream does not support packets, "
                                "but supports discarded events: "
                                "stream-addr=%p, "
@@ -656,7 +680,8 @@ bt_component_class_sink_consume_method_status handle_stream_beginning_msg(
        if (!fs_sink->ignore_discarded_events &&
                        bt_stream_class_discarded_events_have_default_clock_snapshots(ir_sc) &&
                        !packets_have_beginning_end_cs) {
-               BT_COMP_LOGE("Unsupported stream: discarded events have "
+               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                       "Unsupported stream: discarded events have "
                        "default clock snapshots, but packets have no "
                        "beginning and/or end default clock snapshots: "
                        "stream-addr=%p, "
@@ -676,7 +701,8 @@ bt_component_class_sink_consume_method_status handle_stream_beginning_msg(
        if (!fs_sink->ignore_discarded_packets &&
                        bt_stream_class_discarded_packets_have_default_clock_snapshots(ir_sc) &&
                        !packets_have_beginning_end_cs) {
-               BT_COMP_LOGE("Unsupported stream: discarded packets have "
+               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                       "Unsupported stream: discarded packets have "
                        "default clock snapshots, but packets have no "
                        "beginning and/or end default clock snapshots: "
                        "stream-addr=%p, "
@@ -690,6 +716,8 @@ bt_component_class_sink_consume_method_status handle_stream_beginning_msg(
 
        stream = borrow_stream(fs_sink, ir_stream);
        if (!stream) {
+               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                       "Failed to borrow stream.");
                status = BT_COMPONENT_CLASS_SINK_CONSUME_METHOD_STATUS_ERROR;
                goto end;
        }
@@ -717,6 +745,8 @@ bt_component_class_sink_consume_method_status handle_stream_end_msg(
 
        stream = borrow_stream(fs_sink, ir_stream);
        if (!stream) {
+               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                       "Failed to borrow stream.");
                status = BT_COMPONENT_CLASS_SINK_CONSUME_METHOD_STATUS_ERROR;
                goto end;
        }
@@ -727,6 +757,8 @@ bt_component_class_sink_consume_method_status handle_stream_end_msg(
                int ret = fs_sink_stream_close_packet(stream, NULL);
 
                if (ret) {
+                       BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                               "Failed to close packet.");
                        status = BT_COMPONENT_CLASS_SINK_CONSUME_METHOD_STATUS_ERROR;
                        goto end;
                }
@@ -764,6 +796,8 @@ bt_component_class_sink_consume_method_status handle_discarded_events_msg(
 
        stream = borrow_stream(fs_sink, ir_stream);
        if (!stream) {
+               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                       "Failed to borrow stream.");
                status = BT_COMPONENT_CLASS_SINK_CONSUME_METHOD_STATUS_ERROR;
                goto end;
        }
@@ -781,7 +815,8 @@ bt_component_class_sink_consume_method_status handle_discarded_events_msg(
        }
 
        if (stream->discarded_events_state.in_range) {
-               BT_COMP_LOGE("Unsupported contiguous discarded events message: "
+               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                       "Unsupported contiguous discarded events message: "
                        "stream-id=%" PRIu64 ", stream-name=\"%s\", "
                        "trace-name=\"%s\", path=\"%s/%s\"",
                        bt_stream_get_id(ir_stream),
@@ -803,7 +838,8 @@ bt_component_class_sink_consume_method_status handle_discarded_events_msg(
         */
        if (stream->packet_state.is_open &&
                        stream->sc->discarded_events_has_ts) {
-               BT_COMP_LOGE("Unsupported discarded events message with "
+               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                       "Unsupported discarded events message with "
                        "default clock snapshots occurring within a packet: "
                        "stream-id=%" PRIu64 ", stream-name=\"%s\", "
                        "trace-name=\"%s\", path=\"%s/%s\"",
@@ -872,6 +908,8 @@ bt_component_class_sink_consume_method_status handle_discarded_packets_msg(
 
        stream = borrow_stream(fs_sink, ir_stream);
        if (!stream) {
+               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                       "Failed to borrow stream.");
                status = BT_COMPONENT_CLASS_SINK_CONSUME_METHOD_STATUS_ERROR;
                goto end;
        }
@@ -889,7 +927,8 @@ bt_component_class_sink_consume_method_status handle_discarded_packets_msg(
        }
 
        if (stream->discarded_packets_state.in_range) {
-               BT_COMP_LOGE("Unsupported contiguous discarded packets message: "
+               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                       "Unsupported contiguous discarded packets message: "
                        "stream-id=%" PRIu64 ", stream-name=\"%s\", "
                        "trace-name=\"%s\", path=\"%s/%s\"",
                        bt_stream_get_id(ir_stream),
@@ -979,6 +1018,8 @@ bt_component_class_sink_consume_method_status ctf_fs_sink_consume(
                fs_sink->upstream_iter, &msgs, &msg_count);
        if (next_status < 0) {
                status = (int) next_status;
+               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                       "Failed to get next message from upstream iterator.");
                goto end;
        }
 
@@ -1031,7 +1072,8 @@ bt_component_class_sink_consume_method_status ctf_fs_sink_consume(
                        BT_MESSAGE_PUT_REF_AND_RESET(msgs[i]);
 
                        if (status != BT_COMPONENT_CLASS_SINK_CONSUME_METHOD_STATUS_OK) {
-                               BT_COMP_LOGE("Failed to handle message: "
+                               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                                       "Failed to handle message: "
                                        "generated CTF traces could be incomplete: "
                                        "output-dir-path=\"%s\"",
                                        fs_sink->output_dir_path->str);
@@ -1080,6 +1122,8 @@ ctf_fs_sink_graph_is_configured(
                                self_comp, in_port_name), &fs_sink->upstream_iter);
        if (msg_iter_status != BT_MESSAGE_ITERATOR_CREATE_FROM_SINK_COMPONENT_STATUS_OK) {
                status = (int) msg_iter_status;
+               BT_COMP_LOGE_APPEND_CAUSE(fs_sink->self_comp,
+                       "Failed to create upstream iterator.");
                goto end;
        }