From 68a69600af7e86172e3f239d3674db37e4c8b11b Mon Sep 17 00:00:00 2001 From: duncanpo Date: Tue, 14 May 2024 11:53:03 -0400 Subject: [PATCH 1/5] refactor startSpan in TracerProxy to improve performance --- api/trace/+opentelemetry/+trace/Span.m | 7 +- api/trace/+opentelemetry/+trace/Tracer.m | 145 +++++++++------ .../opentelemetry-matlab/trace/TracerProxy.h | 15 +- api/trace/src/SpanProxy.cpp | 18 +- api/trace/src/TracerProxy.cpp | 165 +++++++++++++----- 5 files changed, 235 insertions(+), 115 deletions(-) diff --git a/api/trace/+opentelemetry/+trace/Span.m b/api/trace/+opentelemetry/+trace/Span.m index 24a7e5e..7ea4541 100644 --- a/api/trace/+opentelemetry/+trace/Span.m +++ b/api/trace/+opentelemetry/+trace/Span.m @@ -45,16 +45,15 @@ function endSpan(obj, endtime) % % See also OPENTELEMETRY.TRACE.TRACER.STARTSPAN if nargin < 2 - endposixtime = NaN; + obj.Proxy.endSpan(); else if ~(isdatetime(endtime) && isscalar(endtime) && ~isnat(endtime)) % invalid end time, ignore - endposixtime = NaN; + obj.Proxy.endSpan(); else - endposixtime = posixtime(endtime); + obj.Proxy.endSpan(posixtime(endtime)); end end - obj.Proxy.endSpan(endposixtime); obj.Ended = true; end diff --git a/api/trace/+opentelemetry/+trace/Tracer.m b/api/trace/+opentelemetry/+trace/Tracer.m index f9af846..4c4b164 100644 --- a/api/trace/+opentelemetry/+trace/Tracer.m +++ b/api/trace/+opentelemetry/+trace/Tracer.m @@ -1,7 +1,7 @@ classdef Tracer < handle % A tracer that is used to create spans. - % Copyright 2023 The MathWorks, Inc. + % Copyright 2023-2024 The MathWorks, Inc. properties (SetAccess=immutable) Name (1,1) string % Tracer name @@ -42,77 +42,108 @@ % a dictionary. % "Links" - Link objects that specifies relationships % with other spans. - % + % % See also OPENTELEMETRY.TRACE.SPAN, % OPENTELEMETRY.TRACE.LINK, OPENTELEMETRY.CONTEXT.CONTEXT - arguments - obj - spname + arguments + obj + spname end arguments (Repeating) trailingnames trailingvalues end + import opentelemetry.common.processAttributes - % validate the trailing names and values - optionnames = ["Context", "SpanKind", "StartTime", "Attributes", "Links"]; - % define default values - contextid = intmax("uint64"); % default value which means no context supplied - spankind = "internal"; - starttime = NaN; - attributekeys = string.empty(); - attributevalues = {}; - links = {}; - % Loop through Name-Value pairs - for i = 1:length(trailingnames) - try - namei = validatestring(trailingnames{i}, optionnames); - catch - % invalid option, ignore - continue - end - if strcmp(namei, "Context") - context = trailingvalues{i}; - if isa(context, "opentelemetry.context.Context") - contextid = context.Proxy.ID; - end - elseif strcmp(namei, "SpanKind") + + if nargin == 2 + spname = opentelemetry.common.mustBeScalarString(spname); + id = obj.Proxy.startSpanWithNameOnly(spname); + spanproxy = libmexclass.proxy.Proxy("Name", ... + "libmexclass.opentelemetry.SpanProxy", "ID", id); + span = opentelemetry.trace.Span(spanproxy, spname); + else + + % validate the trailing names and values + optionnames = ["Context", "SpanKind", "StartTime", "Attributes", "Links"]; + % define default values + contextid = intmax("uint64"); % default value which means no context supplied + spankind = "internal"; + starttime = NaN; + attributekeys = string.empty(); + attributevalues = {}; + links = {}; + % variables to keep track of which proxy function to call + specifyoptions = false; + specifyattributes = false; + + % Loop through Name-Value pairs + for i = 1:length(trailingnames) try - spankind = validatestring(trailingvalues{i}, ... - ["internal", "server", "client", "producer", "consumer"]); + namei = validatestring(trailingnames{i}, optionnames); catch - % invalid span kind. Ignore + % invalid option, ignore + continue end - elseif strcmp(namei, "StartTime") - valuei = trailingvalues{i}; - if isdatetime(valuei) && isscalar(valuei) && ~isnat(valuei) - starttime = posixtime(valuei); - end - elseif strcmp(namei, "Attributes") - [attributekeys, attributevalues] = processAttributes(trailingvalues{i}, true); - elseif strcmp(namei, "Links") - valuei = trailingvalues{i}; - if isa(valuei, "opentelemetry.trace.Link") - nlinks = numel(valuei); - links = cell(3,nlinks); - for li = 1:nlinks - links{1,li} = valuei(li).Target.Proxy.ID; - linkattrs = valuei(li).Attributes; - [linkattrkeys, linkattrvalues] = processAttributes(linkattrs, true); - links{2,li} = linkattrkeys; - links{3,li} = linkattrvalues; + if strcmp(namei, "Context") + context = trailingvalues{i}; + if isa(context, "opentelemetry.context.Context") + contextid = context.Proxy.ID; + specifyoptions = true; end - links = reshape(links,1,[]); % flatten into a row vector + elseif strcmp(namei, "SpanKind") + try + spankind = validatestring(trailingvalues{i}, ... + ["internal", "server", "client", "producer", "consumer"]); + specifyoptions = true; + catch + % invalid span kind. Ignore + end + elseif strcmp(namei, "StartTime") + valuei = trailingvalues{i}; + if isdatetime(valuei) && isscalar(valuei) && ~isnat(valuei) + starttime = posixtime(valuei); + specifyoptions = true; + end + elseif strcmp(namei, "Attributes") + [attributekeys, attributevalues] = processAttributes(trailingvalues{i}, true); + specifyattributes = true; + elseif strcmp(namei, "Links") + valuei = trailingvalues{i}; + if isa(valuei, "opentelemetry.trace.Link") + nlinks = numel(valuei); + links = cell(3,nlinks); + for li = 1:nlinks + links{1,li} = valuei(li).Target.Proxy.ID; + linkattrs = valuei(li).Attributes; + [linkattrkeys, linkattrvalues] = processAttributes(linkattrs, true); + links{2,li} = linkattrkeys; + links{3,li} = linkattrvalues; + end + links = reshape(links,1,[]); % flatten into a row vector + specifyattributes = true; + end + end - end + spname = opentelemetry.common.mustBeScalarString(spname); + if ~specifyoptions && ~specifyattributes + id = obj.Proxy.startSpanWithNameOnly(spname); + elseif specifyoptions && ~specifyattributes + id = obj.Proxy.startSpanWithNameAndOptions(spname, ... + contextid, spankind, starttime); + elseif ~specifyoptions && specifyattributes + id = obj.Proxy.startSpanWithNameAndAttributes(spname, ... + attributekeys, attributevalues, links{:}); + else % specifyoptions && specifyattributes + id = obj.Proxy.startSpanWithNameOptionsAttributes(spname, ... + contextid, spankind, starttime, attributekeys, attributevalues, links{:}); + end + + spanproxy = libmexclass.proxy.Proxy("Name", ... + "libmexclass.opentelemetry.SpanProxy", "ID", id); + span = opentelemetry.trace.Span(spanproxy, spname); end - spname = opentelemetry.common.mustBeScalarString(spname); - id = obj.Proxy.startSpan(spname, contextid, spankind, starttime, ... - attributekeys, attributevalues, links{:}); - spanproxy = libmexclass.proxy.Proxy("Name", ... - "libmexclass.opentelemetry.SpanProxy", "ID", id); - span = opentelemetry.trace.Span(spanproxy, spname); end end diff --git a/api/trace/include/opentelemetry-matlab/trace/TracerProxy.h b/api/trace/include/opentelemetry-matlab/trace/TracerProxy.h index ac047a0..fd7b99e 100644 --- a/api/trace/include/opentelemetry-matlab/trace/TracerProxy.h +++ b/api/trace/include/opentelemetry-matlab/trace/TracerProxy.h @@ -1,4 +1,4 @@ -// Copyright 2023 The MathWorks, Inc. +// Copyright 2023-2024 The MathWorks, Inc. #pragma once @@ -14,10 +14,19 @@ namespace libmexclass::opentelemetry { class TracerProxy : public libmexclass::proxy::Proxy { public: TracerProxy(nostd::shared_ptr tr) : CppTracer(tr) { - REGISTER_METHOD(TracerProxy, startSpan); + REGISTER_METHOD(TracerProxy, startSpanWithNameOnly); + REGISTER_METHOD(TracerProxy, startSpanWithNameAndOptions); + REGISTER_METHOD(TracerProxy, startSpanWithNameAndAttributes); + REGISTER_METHOD(TracerProxy, startSpanWithNameOptionsAttributes); } - void startSpan(libmexclass::proxy::method::Context& context); + void startSpanWithNameOnly(libmexclass::proxy::method::Context& context); + + void startSpanWithNameAndOptions(libmexclass::proxy::method::Context& context); + + void startSpanWithNameAndAttributes(libmexclass::proxy::method::Context& context); + + void startSpanWithNameOptionsAttributes(libmexclass::proxy::method::Context& context); private: diff --git a/api/trace/src/SpanProxy.cpp b/api/trace/src/SpanProxy.cpp index d09a047..bdcd863 100644 --- a/api/trace/src/SpanProxy.cpp +++ b/api/trace/src/SpanProxy.cpp @@ -1,4 +1,4 @@ -// Copyright 2023 The MathWorks, Inc. +// Copyright 2023-2024 The MathWorks, Inc. #include "opentelemetry-matlab/trace/SpanProxy.h" #include "opentelemetry-matlab/trace/ScopeProxy.h" @@ -34,9 +34,9 @@ libmexclass::proxy::MakeResult SpanProxy::make(const libmexclass::proxy::Functio } void SpanProxy::endSpan(libmexclass::proxy::method::Context& context) { - matlab::data::TypedArray endtime_mda = context.inputs[0]; - double endtime = endtime_mda[0]; // number of seconds since 1/1/1970 (i.e. POSIX time) - if (endtime==endtime) { // not NaN. NaN means not specified + if (context.inputs.getNumberOfElements() > 0) { + matlab::data::TypedArray endtime_mda = context.inputs[0]; + double endtime = endtime_mda[0]; // number of seconds since 1/1/1970 (i.e. POSIX time) trace_api::EndSpanOptions options; // conversion between system_time and steady_time common::SystemTimestamp end_system_time{std::chrono::duration(endtime)}; @@ -87,7 +87,7 @@ void SpanProxy::addEvent(libmexclass::proxy::method::Context& context) { std::string eventname = static_cast(eventname_mda[0]); matlab::data::TypedArray eventtime_mda = context.inputs[1]; common::SystemTimestamp eventtime{std::chrono::duration{eventtime_mda[0]}}; - size_t nin = context.inputs.getNumberOfElements(); + const size_t nin = context.inputs.getNumberOfElements(); // attributes ProcessedAttributes eventattrs; for (size_t i = 2, count = 0; i < nin; i += 2, ++count) { @@ -106,17 +106,17 @@ void SpanProxy::addEvent(libmexclass::proxy::method::Context& context) { void SpanProxy::setStatus(libmexclass::proxy::method::Context& context) { matlab::data::StringArray status_mda = context.inputs[0]; - std::string status = static_cast(status_mda[0]); + matlab::data::MATLABString status = status_mda[0]; matlab::data::StringArray descr_mda = context.inputs[1]; std::string descr = static_cast(descr_mda[0]); trace_api::StatusCode code; - if (status.compare("Unset")==0) { + if (status->compare(u"Unset")==0) { code = trace_api::StatusCode::kUnset; - } else if (status.compare("Ok")==0) { + } else if (status->compare(u"Ok")==0) { code = trace_api::StatusCode::kOk; } else { - assert(status.compare("Error")==0); + assert(status->compare(u"Error")==0); code = trace_api::StatusCode::kError; } CppSpan->SetStatus(code, descr); diff --git a/api/trace/src/TracerProxy.cpp b/api/trace/src/TracerProxy.cpp index e6260a0..0242ab5 100644 --- a/api/trace/src/TracerProxy.cpp +++ b/api/trace/src/TracerProxy.cpp @@ -1,4 +1,4 @@ -// Copyright 2023 The MathWorks, Inc. +// Copyright 2023-2024 The MathWorks, Inc. #include "opentelemetry-matlab/trace/TracerProxy.h" #include "opentelemetry-matlab/trace/SpanProxy.h" @@ -12,44 +12,53 @@ #include namespace libmexclass::opentelemetry { -void TracerProxy::startSpan(libmexclass::proxy::method::Context& context) { - size_t ninputs = context.inputs.getNumberOfElements(); - const size_t nfixedinputs = 6; - assert(ninputs >= nfixedinputs && (ninputs - nfixedinputs) % 3 == 0); // each link uses 3 inputs - +const libmexclass::proxy::ID NOPARENTID(-1); // wrap around to intmax + +// Helper function to create a span proxy from a otel-cpp Span object +matlab::data::TypedArray createSpanProxy( + nostd::shared_ptr sp) { + auto spproxy = std::shared_ptr(new SpanProxy(sp)); + + // obtain a proxy ID + libmexclass::proxy::ID proxyid = libmexclass::proxy::ProxyManager::manageProxy(spproxy); + + // return the ID + matlab::data::ArrayFactory factory; + + return factory.createScalar(proxyid); +} + +// startSpan with only span name and no optional inputs +void TracerProxy::startSpanWithNameOnly(libmexclass::proxy::method::Context& context) { matlab::data::StringArray name_mda = context.inputs[0]; std::string name = static_cast(name_mda[0]); - matlab::data::TypedArray parentid_mda = context.inputs[1]; - libmexclass::proxy::ID parentid = parentid_mda[0]; - libmexclass::proxy::ID noparentid(-1); // wrap around to intmax - matlab::data::StringArray kind_mda = context.inputs[2]; - std::string kindstr = static_cast(kind_mda[0]); - matlab::data::TypedArray starttime_mda = context.inputs[3]; - double starttime = starttime_mda[0]; // number of seconds since 1/1/1970 (i.e. POSIX time) - matlab::data::StringArray attrnames_mda = context.inputs[4]; - size_t nattrs = attrnames_mda.getNumberOfElements(); - matlab::data::CellArray attrvalues_mda = context.inputs[5]; - + auto sp = CppTracer->StartSpan(name); + context.outputs[0] = createSpanProxy(sp); +} + +// Helper function to process parent ID, span kind, and start time inputs, and return an options object +trace_api::StartSpanOptions processOptions(libmexclass::proxy::ID parentid, + matlab::data::MATLABString kindstr, double starttime) { trace_api::StartSpanOptions options; // populate the parent field if supplied // parent - if (parentid != noparentid) { + if (parentid != NOPARENTID) { options.parent = std::static_pointer_cast( libmexclass::proxy::ProxyManager::getProxy(parentid))->getInstance(); } // kind trace_api::SpanKind kind; - if (kindstr.compare("internal")==0) { + if (kindstr->compare(u"internal")==0) { kind = trace_api::SpanKind::kInternal; - } else if (kindstr.compare("server")==0) { + } else if (kindstr->compare(u"server")==0) { kind = trace_api::SpanKind::kServer; - } else if (kindstr.compare("client")==0) { + } else if (kindstr->compare(u"client")==0) { kind = trace_api::SpanKind::kClient; - } else if (kindstr.compare("producer")==0) { + } else if (kindstr->compare(u"producer")==0) { kind = trace_api::SpanKind::kProducer; } else { - assert(kindstr.compare("consumer")==0); + assert(kindstr->compare(u"consumer")==0); kind = trace_api::SpanKind::kConsumer; } options.kind = kind; @@ -60,30 +69,57 @@ void TracerProxy::startSpan(libmexclass::proxy::method::Context& context) { options.start_steady_time = common::SteadyTimestamp{std::chrono::system_clock::time_point(options.start_system_time) - std::chrono::system_clock::now() + std::chrono::steady_clock::now()}; } + return options; +} - // attributes - ProcessedAttributes attrs; +// startSpan implementation with span name and an options object +void TracerProxy::startSpanWithNameAndOptions(libmexclass::proxy::method::Context& context) { + matlab::data::StringArray name_mda = context.inputs[0]; + std::string name = static_cast(name_mda[0]); + + matlab::data::TypedArray parentid_mda = context.inputs[1]; + libmexclass::proxy::ID parentid = parentid_mda[0]; + matlab::data::StringArray kind_mda = context.inputs[2]; + matlab::data::MATLABString kindstr = kind_mda[0]; + matlab::data::TypedArray starttime_mda = context.inputs[3]; + double starttime = starttime_mda[0]; // number of seconds since 1/1/1970 (i.e. POSIX time) + + trace_api::StartSpanOptions options = processOptions(parentid, kindstr, starttime); + + auto sp = CppTracer->StartSpan(name, options); + + context.outputs[0] = createSpanProxy(sp); +} + +// Helper function to process attributes +void processAttributes(const matlab::data::StringArray& attrnames_mda, + const matlab::data::CellArray& attrvalues_mda, + ProcessedAttributes& attrs) { + const size_t nattrs = attrnames_mda.getNumberOfElements(); for (size_t i = 0; i < nattrs; ++i) { std::string attrname = static_cast(attrnames_mda[i]); matlab::data::Array attrvalue = attrvalues_mda[i]; processAttribute(attrname, attrvalue, attrs); } +} - // links +// Helper function to process links +std::list > > > processLinks( + const matlab::data::Array& contextinputs, size_t linkstartindex, ProcessedAttributes& linkattrs) { + const size_t ninputs = contextinputs.getNumberOfElements(); std::list > > > links; - ProcessedAttributes linkattrs; - for (size_t i = nfixedinputs; i < ninputs; i+=3) { + for (size_t i = linkstartindex; i < ninputs; i+=3) { // link target - matlab::data::TypedArray linktargetid_mda = context.inputs[i]; + matlab::data::TypedArray linktargetid_mda = contextinputs[i]; libmexclass::proxy::ID linktargetid = linktargetid_mda[0]; std::shared_ptr linktarget = std::static_pointer_cast( libmexclass::proxy::ProxyManager::getProxy(linktargetid)); // link attributes - matlab::data::StringArray linkattrnames_mda = context.inputs[i+1]; - size_t nlinkattrs = linkattrnames_mda.getNumberOfElements(); - matlab::data::Array linkattrvalues_mda = context.inputs[i+2]; + matlab::data::StringArray linkattrnames_mda = contextinputs[i+1]; + const size_t nlinkattrs = linkattrnames_mda.getNumberOfElements(); + matlab::data::Array linkattrvalues_mda = contextinputs[i+2]; for (size_t ii = 0; ii < nlinkattrs; ++ii) { std::string linkattrname = static_cast(linkattrnames_mda[ii]); matlab::data::Array linkattrvalue = linkattrvalues_mda[ii]; @@ -92,19 +128,64 @@ void TracerProxy::startSpan(libmexclass::proxy::method::Context& context) { } links.push_back(std::pair(linktarget->getInstance(), linkattrs.Attributes)); } + return links; +} - auto sp = CppTracer->StartSpan(name, attrs.Attributes, links, options); +// startSpan implementation with span name, attributes, and links +void TracerProxy::startSpanWithNameAndAttributes(libmexclass::proxy::method::Context& context) { + const size_t ninputs = context.inputs.getNumberOfElements(); + const size_t nfixedinputs = 3; + assert(ninputs >= nfixedinputs && (ninputs - nfixedinputs) % 3 == 0); // each link uses 3 inputs + + matlab::data::StringArray name_mda = context.inputs[0]; + std::string name = static_cast(name_mda[0]); - // instantiate a SpanProxy instance - SpanProxy* newproxy = new SpanProxy(sp); - auto spproxy = std::shared_ptr(newproxy); + matlab::data::StringArray attrnames_mda = context.inputs[1]; + matlab::data::CellArray attrvalues_mda = context.inputs[2]; + + // attributes + ProcessedAttributes attrs; + processAttributes(attrnames_mda, attrvalues_mda, attrs); + + // links + ProcessedAttributes linkattrs; + auto links = processLinks(context.inputs, nfixedinputs, linkattrs); + + auto sp = CppTracer->StartSpan(name, attrs.Attributes, links); + + context.outputs[0] = createSpanProxy(sp); +} + +// startSpan implementation with span name, attributes, links, and an options object +void TracerProxy::startSpanWithNameOptionsAttributes(libmexclass::proxy::method::Context& context) { + const size_t ninputs = context.inputs.getNumberOfElements(); + const size_t nfixedinputs = 6; + assert(ninputs >= nfixedinputs && (ninputs - nfixedinputs) % 3 == 0); // each link uses 3 inputs + + matlab::data::StringArray name_mda = context.inputs[0]; + std::string name = static_cast(name_mda[0]); + + matlab::data::TypedArray parentid_mda = context.inputs[1]; + libmexclass::proxy::ID parentid = parentid_mda[0]; + matlab::data::StringArray kind_mda = context.inputs[2]; + matlab::data::MATLABString kindstr = kind_mda[0]; + matlab::data::TypedArray starttime_mda = context.inputs[3]; + double starttime = starttime_mda[0]; // number of seconds since 1/1/1970 (i.e. POSIX time) + matlab::data::StringArray attrnames_mda = context.inputs[4]; + matlab::data::CellArray attrvalues_mda = context.inputs[5]; - // obtain a proxy ID - libmexclass::proxy::ID proxyid = libmexclass::proxy::ProxyManager::manageProxy(spproxy); + trace_api::StartSpanOptions options = processOptions(parentid, kindstr, starttime); - // return the ID - matlab::data::ArrayFactory factory; - auto proxyid_mda = factory.createScalar(proxyid); - context.outputs[0] = proxyid_mda; + // attributes + ProcessedAttributes attrs; + processAttributes(attrnames_mda, attrvalues_mda, attrs); + + // links + ProcessedAttributes linkattrs; + auto links = processLinks(context.inputs, nfixedinputs, linkattrs); + + auto sp = CppTracer->StartSpan(name, attrs.Attributes, links, options); + + context.outputs[0] = createSpanProxy(sp); } } // namespace libmexclass::opentelemetry From 454ae64e348822c75f41320d7e6dd1be4d51026d Mon Sep 17 00:00:00 2001 From: duncanpo Date: Thu, 16 May 2024 14:30:42 -0400 Subject: [PATCH 2/5] metrics performance tests --- test/performance/metricsTest.m | 138 +++++++++++++++++++++++++++++++++ test/performance/traceTest.m | 6 +- 2 files changed, 142 insertions(+), 2 deletions(-) create mode 100644 test/performance/metricsTest.m diff --git a/test/performance/metricsTest.m b/test/performance/metricsTest.m new file mode 100644 index 0000000..a109b0f --- /dev/null +++ b/test/performance/metricsTest.m @@ -0,0 +1,138 @@ +classdef metricsTest < matlab.perftest.TestCase +% performance tests for metrics + +% Copyright 2024 The MathWorks, Inc. + + properties + OtelConfigFile + JsonFile + PidFile + OtelcolName + Otelcol + ListPid + ReadPidList + ExtractPid + Sigint + Sigterm + end + + methods (TestClassSetup) + function setupOnce(testCase) + % add directory where common setup and teardown code lives + utilsfolder = fullfile(fileparts(mfilename('fullpath')), "..", "utils"); + testCase.applyFixture(matlab.unittest.fixtures.PathFixture(utilsfolder)); + + % add the callbacks folder to the path + callbackfolder = fullfile(fileparts(mfilename('fullpath')), "..", "callbacks"); + testCase.applyFixture(matlab.unittest.fixtures.PathFixture(callbackfolder)); + + commonSetupOnce(testCase); + + % create a global meter provider + mp = opentelemetry.sdk.metrics.MeterProvider(); + setMeterProvider(mp); + end + end + + methods (TestMethodSetup) + function setup(testCase) + commonSetup(testCase); + end + end + + methods (TestMethodTeardown) + function teardown(testCase) + % Flush any metrics that have not yet been exported + mp = opentelemetry.metrics.Provider.getMeterProvider(); + opentelemetry.sdk.common.Cleanup.forceFlush(mp); + + commonTeardown(testCase); + end + end + + methods (Test) + function testCounter(testCase) + % create and increment a counter + mt = opentelemetry.metrics.getMeter("foo"); + + testCase.startMeasuring(); + c = createCounter(mt, "bar"); + add(c, 5); + testCase.stopMeasuring(); + end + + function testUpDownCounter(testCase) + % create and increment an up-down-counter + mt = opentelemetry.metrics.getMeter("foo"); + + testCase.startMeasuring(); + c = createUpDownCounter(mt, "bar"); + add(c, -5); + testCase.stopMeasuring(); + end + + function testHistogram(testCase) + % create a histogram and record a value + mt = opentelemetry.metrics.getMeter("foo"); + + testCase.startMeasuring(); + h = createHistogram(mt, "bar"); + record(h, 111); + testCase.stopMeasuring(); + end + + function testObservableCounter(testCase) + % create an observable counter + mt = opentelemetry.metrics.getMeter("foo"); + + testCase.startMeasuring(); + c = createObservableCounter(mt, @callbackNoAttributes, "bar"); %#ok<*NASGU> + testCase.stopMeasuring(); + end + + function testObservableUpDownCounter(testCase) + % create an observable up-down-counter + mt = opentelemetry.metrics.getMeter("foo"); + + testCase.startMeasuring(); + c = createObservableUpDownCounter(mt, @callbackNoAttributes, "bar"); %#ok<*NASGU> + testCase.stopMeasuring(); + end + + function testObservableGauge(testCase) + % create an observable gauge + mt = opentelemetry.metrics.getMeter("foo"); + + testCase.startMeasuring(); + g = createObservableGauge(mt, @callbackNoAttributes, "bar"); + testCase.stopMeasuring(); + end + + function testCounterAttributes(testCase) + % increment counter with attributes + mt = opentelemetry.metrics.getMeter("foo"); + c = createCounter(mt, "bar"); + d = dictionary("Attribute2", "Value2"); + + testCase.startMeasuring(); + add(c, 1, "Attribute1", "Value1") + add(c, 2, d); + add(c, 3, "Attribute3", "Value3"); + testCase.stopMeasuring(); + end + + function testGetMeter(testCase) + % get a meter from the global meter provider instance + testCase.startMeasuring(); + mt = opentelemetry.metrics.getMeter("foo"); + testCase.stopMeasuring(); + end + + function testCreateDefaultMeterProvider(testCase) + % create default MeterProvider in the sdk + testCase.startMeasuring(); + tp = opentelemetry.sdk.metrics.MeterProvider(); + testCase.stopMeasuring(); + end + end +end \ No newline at end of file diff --git a/test/performance/traceTest.m b/test/performance/traceTest.m index 22d21df..a38308a 100644 --- a/test/performance/traceTest.m +++ b/test/performance/traceTest.m @@ -18,8 +18,10 @@ methods (TestClassSetup) function setupOnce(testCase) - testdir = fileparts(mfilename("fullpath")); - addpath(fullfile(testdir, "..", "utils")); % add directory where common setup and teardown code lives + % add directory where common setup and teardown code lives + utilsfolder = fullfile(fileparts(mfilename('fullpath')), "..", "utils"); + testCase.applyFixture(matlab.unittest.fixtures.PathFixture(utilsfolder)); + commonSetupOnce(testCase); % create a global tracer provider From a16b03ed0dec45fe379e41d19a12ed9ea79c763b Mon Sep 17 00:00:00 2001 From: duncanpo Date: Fri, 17 May 2024 13:59:31 -0400 Subject: [PATCH 3/5] logs performance test and some refactoring of metrics performance test --- test/performance/logsTest.m | 102 +++++++++++++++++++++++++++++++++ test/performance/metricsTest.m | 60 +++++++++++++++---- 2 files changed, 150 insertions(+), 12 deletions(-) create mode 100644 test/performance/logsTest.m diff --git a/test/performance/logsTest.m b/test/performance/logsTest.m new file mode 100644 index 0000000..28d509a --- /dev/null +++ b/test/performance/logsTest.m @@ -0,0 +1,102 @@ +classdef logsTest < matlab.perftest.TestCase +% performance tests for logs + +% Copyright 2024 The MathWorks, Inc. + + properties + OtelConfigFile + JsonFile + PidFile + OtelcolName + Otelcol + ListPid + ReadPidList + ExtractPid + Sigint + Sigterm + end + + methods (TestClassSetup) + function setupOnce(testCase) + % add directory where common setup and teardown code lives + utilsfolder = fullfile(fileparts(mfilename('fullpath')), "..", "utils"); + testCase.applyFixture(matlab.unittest.fixtures.PathFixture(utilsfolder)); + + commonSetupOnce(testCase); + + % create a global logger provider + import opentelemetry.sdk.logs.* + lp = LoggerProvider(BatchLogRecordProcessor()); + setLoggerProvider(lp); + end + end + + methods (TestMethodSetup) + function setup(testCase) + commonSetup(testCase); + end + end + + methods (TestMethodTeardown) + function teardown(testCase) + % Flush any log records that have not yet been exported + lp = opentelemetry.logs.Provider.getLoggerProvider(); + opentelemetry.sdk.common.Cleanup.forceFlush(lp); + + commonTeardown(testCase); + end + end + + methods (Test) + function testEmitLogRecord(testCase) + % create and emit a log record + lg = opentelemetry.logs.getLogger("foo"); + + testCase.startMeasuring(); + % run through a loop since the time for 1 iteration is too short + for i = 1:10 + emitLogRecord(lg, "info", "bar"); + end + testCase.stopMeasuring(); + end + + function testAttributes(testCase) + % create and emit a log record with attributes + lg = opentelemetry.logs.getLogger("foo"); + attrs = dictionary(["attribute1", "attribute2"], ["value1", "value2"]); + + testCase.startMeasuring(); + emitLogRecord(lg, "info", "bar", Attributes=attrs); + testCase.stopMeasuring(); + end + + function testFrontEndAPI(testCase) + % Call frontend API functions to emit a log record (trace, + % debug, info, warn, error, fatal) + lg = opentelemetry.logs.getLogger("foo"); + + testCase.startMeasuring(); + trace(lg, "bar"); + debug(lg, "bar"); + info(lg, "bar"); + warn(lg, "bar"); + error(lg, "bar"); + fatal(lg, "bar"); + testCase.stopMeasuring(); + end + + function testGetLogger(testCase) + % get a logger from the global logger provider instance + testCase.startMeasuring(); + lg = opentelemetry.logs.getLogger("foo"); %#ok<*NASGU> + testCase.stopMeasuring(); + end + + function testCreateDefaultLoggerProvider(testCase) + % create default LoggerProvider in the sdk + testCase.startMeasuring(); + lp = opentelemetry.sdk.logs.LoggerProvider(); + testCase.stopMeasuring(); + end + end +end \ No newline at end of file diff --git a/test/performance/metricsTest.m b/test/performance/metricsTest.m index a109b0f..4e10351 100644 --- a/test/performance/metricsTest.m +++ b/test/performance/metricsTest.m @@ -51,37 +51,34 @@ function teardown(testCase) end methods (Test) - function testCounter(testCase) - % create and increment a counter + function testCreateCounter(testCase) + % create a counter mt = opentelemetry.metrics.getMeter("foo"); testCase.startMeasuring(); c = createCounter(mt, "bar"); - add(c, 5); testCase.stopMeasuring(); end - function testUpDownCounter(testCase) - % create and increment an up-down-counter + function testCreateUpDownCounter(testCase) + % create an up-down-counter mt = opentelemetry.metrics.getMeter("foo"); testCase.startMeasuring(); c = createUpDownCounter(mt, "bar"); - add(c, -5); testCase.stopMeasuring(); end - function testHistogram(testCase) - % create a histogram and record a value + function testCreateHistogram(testCase) + % create a histogram mt = opentelemetry.metrics.getMeter("foo"); testCase.startMeasuring(); h = createHistogram(mt, "bar"); - record(h, 111); testCase.stopMeasuring(); end - function testObservableCounter(testCase) + function testCreateObservableCounter(testCase) % create an observable counter mt = opentelemetry.metrics.getMeter("foo"); @@ -90,7 +87,7 @@ function testObservableCounter(testCase) testCase.stopMeasuring(); end - function testObservableUpDownCounter(testCase) + function testCreateObservableUpDownCounter(testCase) % create an observable up-down-counter mt = opentelemetry.metrics.getMeter("foo"); @@ -99,7 +96,7 @@ function testObservableUpDownCounter(testCase) testCase.stopMeasuring(); end - function testObservableGauge(testCase) + function testCreateObservableGauge(testCase) % create an observable gauge mt = opentelemetry.metrics.getMeter("foo"); @@ -108,6 +105,45 @@ function testObservableGauge(testCase) testCase.stopMeasuring(); end + function testCounterAdd(testCase) + % increment a counter + mt = opentelemetry.metrics.getMeter("foo"); + c = createCounter(mt, "bar"); + + testCase.startMeasuring(); + % run through a loop since the time for 1 iteration is too short + for i = 1:10 + add(c, 5); + end + testCase.stopMeasuring(); + end + + function testUpDownCounterAdd(testCase) + % Increment an up-down-counter + mt = opentelemetry.metrics.getMeter("foo"); + c = createUpDownCounter(mt, "bar"); + + testCase.startMeasuring(); + % run through a loop since the time for 1 iteration is too short + for i = 1:10 + add(c, -5); + end + testCase.stopMeasuring(); + end + + function testHistogramRecord(testCase) + % record a histogram value + mt = opentelemetry.metrics.getMeter("foo"); + h = createHistogram(mt, "bar"); + + testCase.startMeasuring(); + % run through a loop since the time for 1 iteration is too short + for i = 1:10 + record(h, 111); + end + testCase.stopMeasuring(); + end + function testCounterAttributes(testCase) % increment counter with attributes mt = opentelemetry.metrics.getMeter("foo"); From 438453b0c8b3785fe49de5521a2e1e5b372e29b0 Mon Sep 17 00:00:00 2001 From: duncanpo Date: Mon, 20 May 2024 11:32:18 -0400 Subject: [PATCH 4/5] Performance improvement in logs --- api/logs/+opentelemetry/+logs/Logger.m | 96 ++++++++++++++++---------- api/logs/src/LoggerProxy.cpp | 80 +++++++++++---------- 2 files changed, 104 insertions(+), 72 deletions(-) diff --git a/api/logs/+opentelemetry/+logs/Logger.m b/api/logs/+opentelemetry/+logs/Logger.m index d8b4181..395b100 100644 --- a/api/logs/+opentelemetry/+logs/Logger.m +++ b/api/logs/+opentelemetry/+logs/Logger.m @@ -65,8 +65,10 @@ function emitLogRecord(obj, severity, body, trailingnames, trailingvalues) % severity text % Support 24 valid severity levels: trace, trace2, trace3, % trace4, debug, debug2, debug3, ... - severitylist = ["trace", "debug", "info", "warn", "error", "fatal"]; - severitylist = reshape(severitylist + [""; "2"; "3"; "4"], 1, []); + severitylist = ["trace" "trace2" "trace3" "trace4" "debug" ... + "debug2" "debug3" "debug4" "info" "info2" "info3" "info4" ... + "warn" "warn2" "warn3" "warn4" "error" "error2" "error3" ... + "error4" "fatal" "fatal2" "fatal3" "fatal4"]; d = dictionary(severitylist, 1:length(severitylist)); try severity = d(lower(severity)); @@ -81,39 +83,59 @@ function emitLogRecord(obj, severity, body, trailingnames, trailingvalues) % body body = convertCharsToStrings(body); % force char rows into strings - % validate the trailing names and values - optionnames = ["Context", "Timestamp", "Attributes"]; - - % define default values - contextid = intmax("uint64"); % default value which means no context supplied - timestamp = NaN; - attributekeys = string.empty(); - attributevalues = {}; - - % Loop through Name-Value pairs - for i = 1:length(trailingnames) - try - namei = validatestring(trailingnames{i}, optionnames); - catch - % invalid option, ignore - continue - end - if strcmp(namei, "Context") - context = trailingvalues{i}; - if isa(context, "opentelemetry.context.Context") - contextid = context.Proxy.ID; + if nargin <= 3 + obj.Proxy.emitLogRecord(severity, body); + else + % validate the trailing names and values + optionnames = ["Context", "Timestamp", "Attributes"]; + + % define default values + contextid = intmax("uint64"); % default value which means no context supplied + timestamp = NaN; + attributekeys = string.empty(); + attributevalues = {}; + + % variables to keep track of which proxy function to call + specifyoptions = false; + specifyattributes = false; + + % Loop through Name-Value pairs + for i = 1:length(trailingnames) + try + namei = validatestring(trailingnames{i}, optionnames); + catch + % invalid option, ignore + continue end - elseif strcmp(namei, "Timestamp") - valuei = trailingvalues{i}; - if isdatetime(valuei) && isscalar(valuei) && ~isnat(valuei) - timestamp = posixtime(valuei); + if strcmp(namei, "Context") + context = trailingvalues{i}; + if isa(context, "opentelemetry.context.Context") + contextid = context.Proxy.ID; + specifyoptions = true; + end + elseif strcmp(namei, "Timestamp") + valuei = trailingvalues{i}; + if isdatetime(valuei) && isscalar(valuei) && ~isnat(valuei) + timestamp = posixtime(valuei); + specifyoptions = true; + end + elseif strcmp(namei, "Attributes") + [attributekeys, attributevalues] = processAttributes(trailingvalues{i}, true); + specifyattributes = true; end - elseif strcmp(namei, "Attributes") - [attributekeys, attributevalues] = processAttributes(trailingvalues{i}, true); + end + + if ~specifyoptions && ~specifyattributes + obj.Proxy.emitLogRecord(severity, body); + elseif specifyoptions && ~specifyattributes + obj.Proxy.emitLogRecord(severity, body, contextid, timestamp); + elseif ~specifyoptions && specifyattributes + obj.Proxy.emitLogRecord(severity, body, attributekeys, attributevalues); + else % specifyoptions && specifyattributes + obj.Proxy.emitLogRecord(severity, body, contextid, timestamp, ... + attributekeys, attributevalues); end end - obj.Proxy.emitLogRecord(severity, body, contextid, timestamp, ... - attributekeys, attributevalues); end function trace(obj, body, varargin) @@ -134,7 +156,7 @@ function trace(obj, body, varargin) % OPENTELEMETRY.LOGS.INFO, OPENTELEMETRY.LOGS.WARN, % OPENTELEMETRY.LOGS.ERROR, OPENTELEMETRY.LOGS.FATAL, % OPENTELEMETRY.LOGS.EMITLOGRECORD - emitLogRecord(obj, "trace", body, varargin{:}); + emitLogRecord(obj, 1, body, varargin{:}); end function debug(obj, body, varargin) @@ -155,7 +177,7 @@ function debug(obj, body, varargin) % OPENTELEMETRY.LOGS.INFO, OPENTELEMETRY.LOGS.WARN, % OPENTELEMETRY.LOGS.ERROR, OPENTELEMETRY.LOGS.FATAL, % OPENTELEMETRY.LOGS.EMITLOGRECORD - emitLogRecord(obj, "debug", body, varargin{:}); + emitLogRecord(obj, 5, body, varargin{:}); end function info(obj, body, varargin) @@ -176,7 +198,7 @@ function info(obj, body, varargin) % OPENTELEMETRY.LOGS.DEBUG, OPENTELEMETRY.LOGS.WARN, % OPENTELEMETRY.LOGS.ERROR, OPENTELEMETRY.LOGS.FATAL, % OPENTELEMETRY.LOGS.EMITLOGRECORD - emitLogRecord(obj, "info", body, varargin{:}); + emitLogRecord(obj, 9, body, varargin{:}); end function warn(obj, body, varargin) @@ -197,7 +219,7 @@ function warn(obj, body, varargin) % OPENTELEMETRY.LOGS.DEBUG, OPENTELEMETRY.LOGS.INFO, % OPENTELEMETRY.LOGS.ERROR, OPENTELEMETRY.LOGS.FATAL, % OPENTELEMETRY.LOGS.EMITLOGRECORD - emitLogRecord(obj, "warn", body, varargin{:}); + emitLogRecord(obj, 13, body, varargin{:}); end function error(obj, body, varargin) @@ -218,7 +240,7 @@ function error(obj, body, varargin) % OPENTELEMETRY.LOGS.DEBUG, OPENTELEMETRY.LOGS.INFO, % OPENTELEMETRY.LOGS.WARN, OPENTELEMETRY.LOGS.FATAL, % OPENTELEMETRY.LOGS.EMITLOGRECORD - emitLogRecord(obj, "error", body, varargin{:}); + emitLogRecord(obj, 17, body, varargin{:}); end function fatal(obj, body, varargin) @@ -239,7 +261,7 @@ function fatal(obj, body, varargin) % OPENTELEMETRY.LOGS.DEBUG, OPENTELEMETRY.LOGS.INFO, % OPENTELEMETRY.LOGS.WARN, OPENTELEMETRY.LOGS.ERROR, % OPENTELEMETRY.LOGS.EMITLOGRECORD - emitLogRecord(obj, "fatal", body, varargin{:}); + emitLogRecord(obj, 21, body, varargin{:}); end end diff --git a/api/logs/src/LoggerProxy.cpp b/api/logs/src/LoggerProxy.cpp index bbdb055..6d5ac6f 100644 --- a/api/logs/src/LoggerProxy.cpp +++ b/api/logs/src/LoggerProxy.cpp @@ -20,17 +20,10 @@ namespace nostd = opentelemetry::nostd; namespace libmexclass::opentelemetry { void LoggerProxy::emitLogRecord(libmexclass::proxy::method::Context& context) { + const size_t ninputs = context.inputs.getNumberOfElements(); matlab::data::TypedArray severity_mda = context.inputs[0]; int severity = static_cast(severity_mda[0]); matlab::data::Array body_mda = context.inputs[1]; - matlab::data::TypedArray contextid_mda = context.inputs[2]; - libmexclass::proxy::ID contextid = contextid_mda[0]; - libmexclass::proxy::ID nocontextid(-1); // wrap around to intmax - matlab::data::TypedArray timestamp_mda = context.inputs[3]; - double timestamp = timestamp_mda[0]; // number of seconds since 1/1/1970 (i.e. POSIX time) - matlab::data::StringArray attrnames_mda = context.inputs[4]; - size_t nattrs = attrnames_mda.getNumberOfElements(); - matlab::data::CellArray attrvalues_mda = context.inputs[5]; // log body ProcessedAttributes bodyattrs; @@ -47,39 +40,56 @@ void LoggerProxy::emitLogRecord(libmexclass::proxy::method::Context& context) { nostd::unique_ptr rec = CppLogger->CreateLogRecord(); - // context - if (contextid != nocontextid) { - context_api::Context supplied_context = std::static_pointer_cast( - libmexclass::proxy::ProxyManager::getProxy(contextid))->getInstance(); - trace_api::SpanContext sc = trace_api::GetSpan(supplied_context)->GetContext(); - rec->SetTraceId(sc.trace_id()); - rec->SetSpanId(sc.span_id()); - rec->SetTraceFlags(sc.trace_flags()); + // Add size attribute if body is nonscalar + if (array_body) { + rec->SetAttribute(bodyattrs.Attributes.back().first, bodyattrs.Attributes.back().second); } - // timestamp - if (timestamp == timestamp) { // not NaN. NaN means not specified - rec->SetTimestamp(common::SystemTimestamp{std::chrono::duration(timestamp)}); - } + if (ninputs > 2) { + size_t curridx = 2; + matlab::data::Array firstoption = context.inputs[curridx]; // check third input type whether it's a proxy ID + bool first_option_is_id = (firstoption.getType() == matlab::data::ArrayType::UINT64); + if (first_option_is_id) { + // context + matlab::data::TypedArray contextid_mda = context.inputs[curridx++]; + libmexclass::proxy::ID contextid = contextid_mda[0]; + const libmexclass::proxy::ID nocontextid = -1; // wrap around to intmax + if (contextid != nocontextid) { + context_api::Context supplied_context = std::static_pointer_cast( + libmexclass::proxy::ProxyManager::getProxy(contextid))->getInstance(); + trace_api::SpanContext sc = trace_api::GetSpan(supplied_context)->GetContext(); + rec->SetTraceId(sc.trace_id()); + rec->SetSpanId(sc.span_id()); + rec->SetTraceFlags(sc.trace_flags()); + } - // attributes - ProcessedAttributes attrs; - if (nattrs > 0) { - for (size_t i = 0; i < nattrs; ++i) { - std::string attrname = static_cast(attrnames_mda[i]); - matlab::data::Array attrvalue = attrvalues_mda[i]; + // timestamp + matlab::data::TypedArray timestamp_mda = context.inputs[curridx++]; + double timestamp = timestamp_mda[0]; // number of seconds since 1/1/1970 (i.e. POSIX time) + if (timestamp == timestamp) { // not NaN. NaN means not specified + rec->SetTimestamp(common::SystemTimestamp{std::chrono::duration(timestamp)}); + } + } + + if (!first_option_is_id || ninputs > 4) { + // attributes + matlab::data::StringArray attrnames_mda = context.inputs[curridx++]; + size_t nattrs = attrnames_mda.getNumberOfElements(); + matlab::data::CellArray attrvalues_mda = context.inputs[curridx]; + ProcessedAttributes attrs; + if (nattrs > 0) { + for (size_t i = 0; i < nattrs; ++i) { + std::string attrname = static_cast(attrnames_mda[i]); + matlab::data::Array attrvalue = attrvalues_mda[i]; - processAttribute(attrname, attrvalue, attrs); + processAttribute(attrname, attrvalue, attrs); + } + auto record_attribute = [&](const std::pair attr) + {rec->SetAttribute(attr.first, attr.second);}; + std::for_each(attrs.Attributes.cbegin(), attrs.Attributes.cend(), record_attribute); + } } - auto record_attribute = [&](const std::pair attr) - {rec->SetAttribute(attr.first, attr.second);}; - std::for_each(attrs.Attributes.cbegin(), attrs.Attributes.cend(), record_attribute); - } - // Add size attribute if body is nonscalar - if (array_body) { - rec->SetAttribute(bodyattrs.Attributes.back().first, bodyattrs.Attributes.back().second); } - CppLogger->EmitLogRecord(std::move(rec), static_cast(severity), log_body); } } // namespace libmexclass::opentelemetry From bb7fc22916f1e68defa7f8721f676c45038d851d Mon Sep 17 00:00:00 2001 From: duncanpo Date: Tue, 21 May 2024 10:49:38 -0400 Subject: [PATCH 5/5] use keepMeasuring in performance tests instead of explicit looping --- test/performance/logsTest.m | 5 +---- test/performance/metricsTest.m | 15 +++------------ 2 files changed, 4 insertions(+), 16 deletions(-) diff --git a/test/performance/logsTest.m b/test/performance/logsTest.m index 28d509a..7c2b979 100644 --- a/test/performance/logsTest.m +++ b/test/performance/logsTest.m @@ -52,12 +52,9 @@ function testEmitLogRecord(testCase) % create and emit a log record lg = opentelemetry.logs.getLogger("foo"); - testCase.startMeasuring(); - % run through a loop since the time for 1 iteration is too short - for i = 1:10 + while(testCase.keepMeasuring) emitLogRecord(lg, "info", "bar"); end - testCase.stopMeasuring(); end function testAttributes(testCase) diff --git a/test/performance/metricsTest.m b/test/performance/metricsTest.m index 4e10351..945c4b3 100644 --- a/test/performance/metricsTest.m +++ b/test/performance/metricsTest.m @@ -110,12 +110,9 @@ function testCounterAdd(testCase) mt = opentelemetry.metrics.getMeter("foo"); c = createCounter(mt, "bar"); - testCase.startMeasuring(); - % run through a loop since the time for 1 iteration is too short - for i = 1:10 + while(testCase.keepMeasuring) add(c, 5); end - testCase.stopMeasuring(); end function testUpDownCounterAdd(testCase) @@ -123,12 +120,9 @@ function testUpDownCounterAdd(testCase) mt = opentelemetry.metrics.getMeter("foo"); c = createUpDownCounter(mt, "bar"); - testCase.startMeasuring(); - % run through a loop since the time for 1 iteration is too short - for i = 1:10 + while(testCase.keepMeasuring) add(c, -5); end - testCase.stopMeasuring(); end function testHistogramRecord(testCase) @@ -136,12 +130,9 @@ function testHistogramRecord(testCase) mt = opentelemetry.metrics.getMeter("foo"); h = createHistogram(mt, "bar"); - testCase.startMeasuring(); - % run through a loop since the time for 1 iteration is too short - for i = 1:10 + while(testCase.keepMeasuring) record(h, 111); end - testCase.stopMeasuring(); end function testCounterAttributes(testCase)