Add span events and status

core/include/userver/tracing/in_place_span.hpp

@@ -37,7 +37,7 @@ class InPlaceSpan final {
 
 private:
     struct Impl;
-    utils::FastPimpl<Impl, 4224, 8> impl_;
+    utils::FastPimpl<Impl, 4240, 8> impl_;
 };
 
 }  // namespace tracing

core/include/userver/tracing/span.hpp

@@ -33,6 +33,36 @@ class Span final {
 public:
     class Impl;
 
+    /// @brief Operation status code.
+    enum class StatusCode : uint8_t {
+        kUnset,  // Default status.
+        kOk,     // Operation has completed successfully.
+        kError,  // The operation contains an error.
+    };
+
+    /// @brief Create span event
+    struct Event final {
+        /// @brief Constructor.
+        /// @param name Event name.
+        /// @param time_unix_nano Event timestamp.
+        Event(
+            const std::string_view name,
+            double time_unix_nano = std::chrono::duration_cast<std::chrono::nanoseconds>(
+                                        std::chrono::system_clock::now().time_since_epoch()
+            )
+                                        .count()
+        );
+
+        /// @brief Default constructor.
+        Event() = default;
+
+        /// @brief Event timestamp.
+        double time_unix_nano{};
+
+        /// @brief Event name.
+        std::string name;
+    };
+
     explicit Span(
         TracerPtr tracer,
         std::string name,
@@ -157,6 +187,12 @@ class Span final {
     /// @overload AddNonInheritableTag
     void AddNonInheritableTags(const logging::LogExtra&);
 
+    /// Add an event to Span.
+    void AddEvent(const std::string_view event_name);
+
+    /// Set span status.
+    void SetStatus(StatusCode status, const std::string_view description);
+
     /// @brief Sets level for tags logging
     void SetLogLevel(logging::Level log_level);
 

core/include/userver/utils/async.hpp

@@ -41,7 +41,7 @@ struct SpanWrapCall {
 
     struct Impl;
 
-    static constexpr std::size_t kImplSize = 4264;
+    static constexpr std::size_t kImplSize = 4280;
     static constexpr std::size_t kImplAlign = 8;
     utils::FastPimpl<Impl, kImplSize, kImplAlign> pimpl_;
 };

core/src/tracing/span.cpp

@@ -149,6 +149,7 @@ void Span::Impl::PutIntoLogger(logging::impl::TagWriter writer) && {
     }
     writer.PutLogExtra(log_extra_inheritable_);
 
+    LogEvents(writer);
     LogOpenTracing();
 }
 
@@ -368,6 +369,26 @@ void Span::AddTagFrozen(std::string key, logging::LogExtra::Value value) {
     pimpl_->log_extra_inheritable_.Extend(std::move(key), std::move(value), logging::LogExtra::ExtendType::kFrozen);
 }
 
+void Span::AddEvent(const std::string_view event_name) { pimpl_->events_.emplace_back(event_name); }
+
+void Span::SetStatus(StatusCode status, const std::string_view description) {
+    if (status == StatusCode::kUnset) {
+        return;
+    }
+
+    if (status == StatusCode::kError) {
+        // Error description is required by OpenTelemetry
+        AddTag("otel.status_description", std::string{description});
+
+        // Service data
+        AddTag("otel.status_code", "ERROR");
+        AddTag("error", "true");
+    } else {
+        AddTag("otel.status_code", "OK");
+        AddTag("error", "false");
+    }
+}
+
 void Span::SetLink(std::string link) { AddTagFrozen(kLinkTag, std::move(link)); }
 
 void Span::SetParentLink(std::string parent_link) { AddTagFrozen(kParentLinkTag, std::move(parent_link)); }
@@ -412,6 +433,8 @@ const Span::Impl* GetParentSpanImpl() {
     return !spans_ptr || spans_ptr->empty() ? nullptr : &spans_ptr->back();
 }
 
+Span::Event::Event(const std::string_view name, double time_unix_nano) : time_unix_nano{time_unix_nano}, name{name} {}
+
 namespace impl {
 
 struct DetachLocalSpansScope::Impl {

core/src/tracing/span_impl.hpp

@@ -76,6 +76,7 @@ class Span::Impl : public boost::intrusive::list_base_hook<boost::intrusive::lin
     void AttachToCoroStack();
 
 private:
+    void LogEvents(logging::impl::TagWriter& writer) const;
     void LogOpenTracing() const;
     void DoLogOpenTracing(logging::impl::TagWriter writer) const;
     static void AddOpentracingTags(formats::json::StringBuilder& output, const logging::LogExtra& input);
@@ -105,6 +106,8 @@ class Span::Impl : public boost::intrusive::list_base_hook<boost::intrusive::lin
     const ReferenceType reference_type_;
     utils::impl::SourceLocation source_location_;
 
+    std::vector<Span::Event> events_;
+
     friend class Span;
     friend class SpanBuilder;
     friend class TagScope;

core/src/tracing/span_opentracing.cpp

@@ -79,6 +79,7 @@ constexpr std::string_view kStartTimeMillis = "start_time_millis";
 constexpr std::string_view kDuration = "duration";
 
 }  // namespace jaeger
+
 }  // namespace
 
 void Span::Impl::LogOpenTracing() const {
@@ -112,15 +113,34 @@ void Span::Impl::DoLogOpenTracing(logging::impl::TagWriter writer) const {
     writer.PutTag(jaeger::kDuration, duration_microseconds);
     writer.PutTag(jaeger::kOperationName, name_);
 
-    formats::json::StringBuilder tags;
     {
+        formats::json::StringBuilder tags;
         const formats::json::StringBuilder::ArrayGuard guard(tags);
         AddOpentracingTags(tags, log_extra_inheritable_);
         if (log_extra_local_) {
             AddOpentracingTags(tags, *log_extra_local_);
         }
+        writer.PutTag("tags", tags.GetStringView());
+    }
+}
+
+void Span::Impl::LogEvents(logging::impl::TagWriter& writer) const {
+    if (events_.empty()) {
+        return;
+    }
+
+    formats::json::StringBuilder events;
+
+    {
+        const formats::json::StringBuilder::ObjectGuard event_guard(events);
+
+        for (const auto& event : events_) {
+            events.Key(event.name);
+            events.WriteDouble(event.time_unix_nano);
+        }
     }
-    writer.PutTag("tags", tags.GetStringView());
+
+    writer.PutTag("events", events.GetStringView());
 }
 
 void Span::Impl::AddOpentracingTags(formats::json::StringBuilder& output, const logging::LogExtra& input) {

otlp/src/otlp/logs/component.cpp

@@ -44,6 +44,15 @@ LoggerComponent::LoggerComponent(const components::ComponentConfig& config, cons
     logger_config.extra_attributes = config["extra-attributes"].As<std::unordered_map<std::string, std::string>>({});
     logger_config.attributes_mapping =
         config["attributes-mapping"].As<std::unordered_map<std::string, std::string>>({});
+
+    // Define error mapping
+    if (logger_config.attributes_mapping.find("otel_status_code") == logger_config.attributes_mapping.end()) {
+        logger_config.attributes_mapping["otel_status_code"] = "otel.status_code";
+    }
+    if (logger_config.attributes_mapping.find("otel_status_description") == logger_config.attributes_mapping.end()) {
+        logger_config.attributes_mapping["otel_status_description"] = "otel.status_description";
+    }
+
     logger_config.logs_sink = config["sinks"]["logs"].As<SinkType>(SinkType::kOtlp);
     logger_config.tracing_sink = config["sinks"]["tracing"].As<SinkType>(SinkType::kOtlp);
 

otlp/src/otlp/logs/logger.cpp

@@ -4,6 +4,7 @@
 #include <iostream>
 
 #include <userver/engine/async.hpp>
+#include <userver/formats/json.hpp>
 #include <userver/formats/parse/common_containers.hpp>
 #include <userver/formats/parse/to.hpp>
 #include <userver/logging/impl/tag_writer.hpp>
@@ -20,11 +21,39 @@ USERVER_NAMESPACE_BEGIN
 namespace otlp {
 
 namespace {
+
 constexpr std::string_view kTelemetrySdkLanguage = "telemetry.sdk.language";
 constexpr std::string_view kTelemetrySdkName = "telemetry.sdk.name";
 constexpr std::string_view kServiceName = "service.name";
 
 const std::string kTimestampFormat = "%Y-%m-%dT%H:%M:%E*S";
+
+std::vector<tracing::Span::Event> GetEventsFromValue(const std::string_view value) {
+    std::vector<tracing::Span::Event> events;
+
+    auto json_value = formats::json::FromString(value);
+
+    if (!json_value.IsObject()) {
+        throw std::runtime_error("Expected JSON object in \"value\"");
+    }
+
+    for (const auto& [key, value] : formats::common::Items(json_value)) {
+        events.emplace_back(key, value.As<double>());
+    }
+
+    return events;
+}
+
+void WriteEventsFromValue(::opentelemetry::proto::trace::v1::Span& span, const std::string_view value) {
+    std::vector<tracing::Span::Event> events = GetEventsFromValue(value);
+
+    for (const auto& event : events) {
+        auto* event_proto = span.add_events();
+        event_proto->set_name(event.name);
+        event_proto->set_time_unix_nano(event.time_unix_nano);
+    }
+}
+
 }  // namespace
 
 SinkType Parse(const yaml_config::YamlConfig& value, formats::parse::To<SinkType>) {
@@ -92,8 +121,9 @@ void Logger::Log(logging::Level level, std::string_view msg) {
 
     ++stats_.by_level[static_cast<int>(level)];
 
-    [[maybe_unused]] auto parse_ok =
-        utils::encoding::TskvReadRecord(parser, [&](std::string_view key, std::string_view value) {
+    [[maybe_unused]] auto parse_ok = utils::encoding::TskvReadRecord(
+        parser,
+        [this, &log_record, &timestamp](std::string_view key, std::string_view value) {
             if (key == "text") {
                 log_record.mutable_body()->set_string_value(grpc::string(std::string{value}));
                 return true;
@@ -119,7 +149,8 @@ void Logger::Log(logging::Level level, std::string_view msg) {
             attributes->set_key(std::string{MapAttribute(key)});
             attributes->mutable_value()->set_string_value(std::string{value});
             return true;
-        });
+        }
+    );
 
     auto nanoseconds = std::chrono::duration_cast<std::chrono::nanoseconds>(timestamp.time_since_epoch());
     log_record.set_time_unix_nano(nanoseconds.count());
@@ -146,8 +177,9 @@ void Logger::Trace(logging::Level level, std::string_view msg) {
     std::string start_timestamp;
     std::string total_time;
 
-    [[maybe_unused]] auto parse_ok =
-        utils::encoding::TskvReadRecord(parser, [&](std::string_view key, std::string_view value) {
+    [[maybe_unused]] auto parse_ok = utils::encoding::TskvReadRecord(
+        parser,
+        [this, &span, &start_timestamp, &total_time](std::string_view key, std::string_view value) {
             if (key == "trace_id") {
                 span.set_trace_id(utils::encoding::FromHex(value));
                 return true;
@@ -175,12 +207,24 @@ void Logger::Trace(logging::Level level, std::string_view msg) {
             if (key == "timestamp" || key == "text") {
                 return true;
             }
+            if (key == "events") {
+                WriteEventsFromValue(span, value);
+                return true;
+            }
+            if (key == "error") {
+                auto attributes = span.add_attributes();
+                attributes->set_key(std::string{key});
+                attributes->mutable_value()->set_bool_value(value == "true");
+
+                return true;
+            }
 
             auto attributes = span.add_attributes();
             attributes->set_key(std::string{MapAttribute(key)});
             attributes->mutable_value()->set_string_value(std::string{value});
             return true;
-        });
+        }
+    );
 
     auto start_timestamp_double = std::stod(start_timestamp);
     span.set_start_time_unix_nano(start_timestamp_double * 1'000'000'000);
@@ -225,7 +269,8 @@ void Logger::SendingLoop(Queue::Consumer& consumer, LogClient& log_client, Trace
                     [&scope_logs](const opentelemetry::proto::logs::v1::LogRecord& action) {
                         auto log_records = scope_logs->add_log_records();
                         *log_records = action;
-                    }},
+                    }
+                },
                 action
             );
         } while (consumer.Pop(action, deadline));