diff --git a/exporters/etw/include/opentelemetry/exporters/etw/etw_properties.h b/exporters/etw/include/opentelemetry/exporters/etw/etw_properties.h index a8864c2cb67..387fcd7a612 100644 --- a/exporters/etw/include/opentelemetry/exporters/etw/etw_properties.h +++ b/exporters/etw/include/opentelemetry/exporters/etw/etw_properties.h @@ -22,6 +22,10 @@ #include #include +#ifdef _WIN32 +# include +#endif + OPENTELEMETRY_BEGIN_NAMESPACE namespace exporter { @@ -178,7 +182,7 @@ class PropertyValue : public PropertyVariant * @param v * @return */ - PropertyValue(const char *value) : PropertyVariant(value){}; + PropertyValue(const char *value) : PropertyVariant(std::string(value)){}; /** * @brief PropertyValue from string. @@ -309,6 +313,7 @@ class PropertyValue : public PropertyVariant case PropertyType::kTypeSpanBool: { const auto &vec = nostd::get>(*this); // FIXME: sort out how to remap from vector to span + UNREFERENCED_PARAMETER(vec); break; } case PropertyType::kTypeSpanInt: diff --git a/exporters/etw/include/opentelemetry/exporters/etw/etw_provider.h b/exporters/etw/include/opentelemetry/exporters/etw/etw_provider.h index ee4e19c2f5e..b377c883749 100644 --- a/exporters/etw/include/opentelemetry/exporters/etw/etw_provider.h +++ b/exporters/etw/include/opentelemetry/exporters/etw/etw_provider.h @@ -22,6 +22,7 @@ # pragma warning(push) # pragma warning(disable : 4459) # pragma warning(disable : 4018) +# pragma warning(disable : 5054) #endif #include "opentelemetry/exporters/etw/etw_properties.h" @@ -52,10 +53,9 @@ #define MICROSOFT_EVENTTAG_NORMAL_PERSISTENCE 0x01000000 -OPENTELEMETRY_BEGIN_NAMESPACE +using namespace OPENTELEMETRY_NAMESPACE::exporter::etw; -using Properties = exporter::etw::Properties; -using PropertyType = exporter::etw::PropertyType; +OPENTELEMETRY_BEGIN_NAMESPACE class ETWProvider { @@ -137,7 +137,6 @@ class ETWProvider switch (format) { -#ifdef HAVE_TLD // Register with TraceLoggingDynamic facility - dynamic manifest ETW events. case EventFormat::ETW_MANIFEST: { tld::ProviderMetadataBuilder> providerMetaBuilder( @@ -164,7 +163,6 @@ class ETWProvider }; }; break; -#endif #ifdef HAVE_MSGPACK // Register for MsgPack payload ETW events. @@ -217,14 +215,12 @@ class ETWProvider data.refCount--; if (data.refCount == 0) { -#ifdef HAVE_TLD if (data.providerMetaVector.size()) { // ETW/TraceLoggingDynamic provider result = tld::UnregisterProvider(data.providerHandle); } else -#endif { // Other provider types, e.g. ETW/MsgPack result = EventUnregister(data.providerHandle); @@ -412,6 +408,11 @@ class ETWProvider }; return (unsigned long)(writeResponse); #else + UNREFERENCED_PARAMETER(providerData); + UNREFERENCED_PARAMETER(eventData); + UNREFERENCED_PARAMETER(ActivityId); + UNREFERENCED_PARAMETER(RelatedActivityId); + UNREFERENCED_PARAMETER(Opcode); return STATUS_ERROR; #endif } @@ -428,7 +429,6 @@ class ETWProvider LPCGUID RelatedActivityId = nullptr, uint8_t Opcode = 0 /* Information */) { -#ifdef HAVE_TLD // Make sure you stop sending event before register unregistering providerData if (providerData.providerHandle == INVALID_HANDLE) { @@ -465,10 +465,7 @@ class ETWProvider for (auto &kv : eventData) { const char *name = kv.first.data(); - // Don't include event name field in the payload - if (EVENT_NAME == name) - continue; - auto &value = kv.second; + auto &value = kv.second; switch (value.index()) { case PropertyType::kTypeBool: { @@ -518,7 +515,7 @@ class ETWProvider dbuilder.AddString(temp); break; } -# if HAVE_TYPE_GUID +#if HAVE_TYPE_GUID // TODO: consider adding UUID/GUID to spec case PropertyType::kGUID: { builder.AddField(name.c_str(), TypeGuid); @@ -526,7 +523,7 @@ class ETWProvider dbuilder.AddBytes(&temp, sizeof(GUID)); break; } -# endif +#endif // TODO: arrays are not supported case PropertyType::kTypeSpanByte: @@ -577,9 +574,6 @@ class ETWProvider }; return (unsigned long)(writeResponse); -#else - return STATUS_ERROR; -#endif } unsigned long write(Handle &providerData, diff --git a/exporters/etw/include/opentelemetry/exporters/etw/etw_tracer.h b/exporters/etw/include/opentelemetry/exporters/etw/etw_tracer.h index 3eecec02d34..8be2381bd70 100644 --- a/exporters/etw/include/opentelemetry/exporters/etw/etw_tracer.h +++ b/exporters/etw/include/opentelemetry/exporters/etw/etw_tracer.h @@ -75,6 +75,8 @@ typedef struct bool enableActivityTracking; // Emit TraceLogging events for Span/Start and Span/Stop bool enableRelatedActivityId; // Assign parent `SpanId` to `RelatedActivityId` bool enableAutoParent; // Start new spans as children of current active span + ETWProvider::EventFormat + encoding; // Event encoding to use for this provider (TLD, MsgPack, XML, etc.). } TracerProviderConfiguration; /** @@ -104,6 +106,72 @@ static inline void GetOption(const TracerProviderOptions &options, } } +/** + * @brief Helper template to convert encoding config option to EventFormat. + * Configuration option passed as `options["encoding"] = "MsgPack"`. + * Default encoding is TraceLogging Dynamic Manifest (TLD). + * + * Valid encoding names listed below. + * + * For MessagePack encoding: + * - "MSGPACK" + * - "MsgPack" + * - "MessagePack" + * + * For XML encoding: + * - "XML" + * - "xml" + * + * For TraceLogging Dynamic encoding: + * - "TLD" + * - "tld" + * + */ +static inline ETWProvider::EventFormat GetEncoding(const TracerProviderOptions &options) +{ + ETWProvider::EventFormat evtFmt = ETWProvider::EventFormat::ETW_MANIFEST; + + auto it = options.find("encoding"); + if (it != options.end()) + { + auto varValue = it->second; + std::string val = nostd::get(varValue); + +#pragma warning(push) +#pragma warning(disable : 4307) /* Integral constant overflow - OK while computing hash */ + auto h = utils::hashCode(val.c_str()); + switch (h) + { + case CONST_HASHCODE(MSGPACK): + // nobrk + case CONST_HASHCODE(MsgPack): + // nobrk + case CONST_HASHCODE(MessagePack): + evtFmt = ETWProvider::EventFormat::ETW_MSGPACK; + break; + + case CONST_HASHCODE(XML): + // nobrk + case CONST_HASHCODE(xml): + evtFmt = ETWProvider::EventFormat::ETW_XML; + break; + + case CONST_HASHCODE(TLD): + // nobrk + case CONST_HASHCODE(tld): + // nobrk + evtFmt = ETWProvider::EventFormat::ETW_MANIFEST; + break; + + default: + break; + } +#pragma warning(pop) + } + + return evtFmt; +} + class Span; /** @@ -215,6 +283,12 @@ TracerProviderConfiguration &GetConfiguration(T &t) return t.config_; } +template +void UpdateStatus(T &t, Properties &props) +{ + t.UpdateStatus(props); +} + /** * @brief Utility method to convert SppanContext.span_id() (8 byte) to ActivityId GUID (16 bytes) * @param span OpenTelemetry Span pointer @@ -399,9 +473,18 @@ class Tracer : public trace::Tracer // since Unix epoch instead of string, but that implies additional tooling // is needed to convert it, rendering it NOT human-readable. evt[ETW_FIELD_STARTTIME] = utils::formatUtcTimestampMsAsISO8601(startTimeMs); - +#ifdef ETW_FIELD_ENDTTIME + // ETW has its own precise timestamp at envelope layer for every event. + // However, in some scenarios it is easier to deal with ISO8601 strings. + // In that case we convert the app-created timestamp and place it into + // Payload[$ETW_FIELD_TIME] field. The option configurable at compile-time. + evt[ETW_FIELD_ENDTTIME] = utils::formatUtcTimestampMsAsISO8601(endTimeMs); +#endif // Duration of Span in milliseconds evt[ETW_FIELD_DURATION] = endTimeMs - startTimeMs; + // Presently we assume that all spans are server spans + evt[ETW_FIELD_SPAN_KIND] = uint32_t(trace::SpanKind::kServer); + UpdateStatus(currentSpan, evt); etwProvider().write(provHandle, evt, ActivityIdPtr, RelatedActivityIdPtr, 0, encoding); } @@ -426,10 +509,6 @@ class Tracer : public trace::Tracer */ ETWProvider::Handle &initProvHandle() { -#if defined(HAVE_MSGPACK) && !defined(HAVE_TLD) - /* Fallback to MsgPack encoding if TraceLoggingDynamic feature gate is off */ - encoding = ETWProvider::EventFormat::ETW_MSGPACK; -#endif isClosed_ = false; return etwProvider().open(provId, encoding); } @@ -687,6 +766,14 @@ class Tracer : public trace::Tracer ActivityIdPtr = &ActivityId; } +#ifdef HAVE_FIELD_TIME + { + auto timeNow = std::chrono::system_clock::now().time_since_epoch(); + auto millis = std::chrono::duration_cast(timeNow).count(); + evt[ETW_FIELD_TIME] = utils::formatUtcTimestampMsAsISO8601(millis); + } +#endif + etwProvider().write(provHandle, evt, ActivityIdPtr, nullptr, 0, encoding); }; @@ -736,6 +823,9 @@ class Span : public trace::Span common::SystemTimestamp start_time_; common::SystemTimestamp end_time_; + trace::StatusCode status_code_{trace::StatusCode::kUnset}; + std::string status_description_; + /** * @brief Owner Tracer of this Span */ @@ -791,6 +881,27 @@ class Span : public trace::Span } public: + /** + * @brief Update Properties object with current Span status + * @param evt + */ + void UpdateStatus(Properties &evt) + { + /* Should we avoid populating this extra field if status is unset? */ + if ((status_code_ == trace::StatusCode::kUnset) || (status_code_ == trace::StatusCode::kOk)) + { + evt[ETW_FIELD_SUCCESS] = "True"; + evt[ETW_FIELD_STATUSCODE] = uint32_t(status_code_); + evt[ETW_FIELD_STATUSMESSAGE] = status_description_; + } + else + { + evt[ETW_FIELD_SUCCESS] = "False"; + evt[ETW_FIELD_STATUSCODE] = uint32_t(status_code_); + evt[ETW_FIELD_STATUSMESSAGE] = status_description_; + } + } + /** * @brief Get start time of this Span. * @return @@ -876,9 +987,8 @@ class Span : public trace::Span */ void SetStatus(trace::StatusCode code, nostd::string_view description) noexcept override { - // TODO: not implemented - UNREFERENCED_PARAMETER(code); - UNREFERENCED_PARAMETER(description); + status_code_ = code; + status_description_ = description.data(); } void SetAttributes(Properties attributes) { attributes_ = attributes; } @@ -1007,6 +1117,9 @@ class TracerProvider : public trace::TracerProvider // When a new Span is started, the current span automatically becomes its parent. GetOption(options, "enableAutoParent", config_.enableAutoParent, false); + + // Determines what encoding to use for ETW events: TraceLogging Dynamic, MsgPack, XML, etc. + config_.encoding = GetEncoding(options); } TracerProvider() : trace::TracerProvider() @@ -1017,6 +1130,7 @@ class TracerProvider : public trace::TracerProvider config_.enableActivityTracking = false; config_.enableRelatedActivityId = false; config_.enableAutoParent = false; + config_.encoding = ETWProvider::EventFormat::ETW_MANIFEST; } /** @@ -1033,44 +1147,8 @@ class TracerProvider : public trace::TracerProvider nostd::shared_ptr GetTracer(nostd::string_view name, nostd::string_view args = "") override { -#if defined(HAVE_MSGPACK) - // Prefer MsgPack over ETW by default - ETWProvider::EventFormat evtFmt = ETWProvider::EventFormat::ETW_MSGPACK; -#else - // Fallback to ETW TraceLoggingDynamic if MsgPack support is not compiled in - ETWProvider::EventFormat evtFmt = ETWProvider::EventFormat::ETW_MANIFEST; -#endif - -#pragma warning(push) -#pragma warning(disable : 4307) /* Integral constant overflow - OK while computing hash */ - auto h = utils::hashCode(args.data()); - switch (h) - { - case CONST_HASHCODE(MSGPACK): - // nobrk - case CONST_HASHCODE(MsgPack): - // nobrk - case CONST_HASHCODE(MessagePack): - evtFmt = ETWProvider::EventFormat::ETW_MSGPACK; - break; - - case CONST_HASHCODE(XML): - // nobrk - case CONST_HASHCODE(xml): - evtFmt = ETWProvider::EventFormat::ETW_XML; - break; - - case CONST_HASHCODE(TLD): - // nobrk - case CONST_HASHCODE(tld): - // nobrk - evtFmt = ETWProvider::EventFormat::ETW_MANIFEST; - break; - - default: - break; - } -#pragma warning(pop) + UNREFERENCED_PARAMETER(args); + ETWProvider::EventFormat evtFmt = config_.encoding; return nostd::shared_ptr{new (std::nothrow) Tracer(*this, name, evtFmt)}; } }; diff --git a/exporters/etw/include/opentelemetry/exporters/etw/utils.h b/exporters/etw/include/opentelemetry/exporters/etw/utils.h index 3c753559017..4e9f431ac4f 100644 --- a/exporters/etw/include/opentelemetry/exporters/etw/utils.h +++ b/exporters/etw/include/opentelemetry/exporters/etw/utils.h @@ -226,7 +226,7 @@ static inline GUID GetProviderGuid(const char *providerName) } #endif -int64_t getUtcSystemTimeMs() +static inline int64_t getUtcSystemTimeMs() { #ifdef _WIN32 ULARGE_INTEGER now; @@ -237,7 +237,7 @@ int64_t getUtcSystemTimeMs() #endif } -int64_t getUtcSystemTimeinTicks() +static inline int64_t getUtcSystemTimeinTicks() { #ifdef _WIN32 FILETIME tocks; @@ -259,9 +259,16 @@ int64_t getUtcSystemTimeinTicks() #endif } -std::string formatUtcTimestampMsAsISO8601(int64_t timestampMs) +/** + * @brief Convert local system milliseconds time to ISO8601 string UTC time + * + * @param timestampMs Milliseconds since epoch in system time + * + * @return ISO8601 UTC string with microseconds part set to 000 + */ +static inline std::string formatUtcTimestampMsAsISO8601(int64_t timestampMs) { - char buf[sizeof("YYYY-MM-DDTHH:MM:SS.sssZ") + 1] = {0}; + char buf[sizeof("YYYY-MM-DDTHH:MM:SS.ssssssZ") + 1] = {0}; #ifdef _WIN32 __time64_t seconds = static_cast<__time64_t>(timestampMs / 1000); int milliseconds = static_cast(timestampMs % 1000); @@ -270,8 +277,8 @@ std::string formatUtcTimestampMsAsISO8601(int64_t timestampMs) { memset(&tm, 0, sizeof(tm)); } - ::_snprintf_s(buf, _TRUNCATE, "%04d-%02d-%02dT%02d:%02d:%02d.%03dZ", 1900 + tm.tm_year, - 1 + tm.tm_mon, tm.tm_mday, tm.tm_hour, tm.tm_min, tm.tm_sec, milliseconds); + ::_snprintf_s(buf, _TRUNCATE, "%04d-%02d-%02dT%02d:%02d:%02d.%06dZ", 1900 + tm.tm_year, + 1 + tm.tm_mon, tm.tm_mday, tm.tm_hour, tm.tm_min, tm.tm_sec, 1000 * milliseconds); #else time_t seconds = static_cast(timestampMs / 1000); int milliseconds = static_cast(timestampMs % 1000); @@ -281,8 +288,8 @@ std::string formatUtcTimestampMsAsISO8601(int64_t timestampMs) { memset(&tm, 0, sizeof(tm)); } - (void)snprintf(buf, sizeof(buf), "%04d-%02d-%02dT%02d:%02d:%02d.%03dZ", 1900 + tm.tm_year, - 1 + tm.tm_mon, tm.tm_mday, tm.tm_hour, tm.tm_min, tm.tm_sec, milliseconds); + (void)snprintf(buf, sizeof(buf), "%04d-%02d-%02dT%02d:%02d:%02d.%06dZ", 1900 + tm.tm_year, + 1 + tm.tm_mon, tm.tm_mday, tm.tm_hour, tm.tm_min, tm.tm_sec, 1000 * milliseconds); #endif return buf; }