Copilot commented on code in PR #12686: URL: https://github.com/apache/apisix/pull/12686#discussion_r2762593711
########## apisix/utils/span.lua: ########## @@ -0,0 +1,101 @@ +-- +-- Licensed to the Apache Software Foundation (ASF) under one or more +-- contributor license agreements. See the NOTICE file distributed with +-- this work for additional information regarding copyright ownership. +-- The ASF licenses this file to You under the Apache License, Version 2.0 +-- (the "License"); you may not use this file except in compliance with +-- the License. You may obtain a copy of the License at +-- +-- http://www.apache.org/licenses/LICENSE-2.0 +-- +-- Unless required by applicable law or agreed to in writing, software +-- distributed under the License is distributed on an "AS IS" BASIS, +-- WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +-- See the License for the specific language governing permissions and +-- limitations under the License. +-- +local tablepool = require("tablepool") +local util = require("opentelemetry.util") +local span_status = require("opentelemetry.trace.span_status") +local setmetatable = setmetatable +local table = table +local select = select +local pool_name = "opentelemetry_span" +local update_time = ngx.update_time + +local _M = {} + + +local mt = { + __index = _M +} + +local function get_time() + update_time() + return util.time_nano() +end + + +function _M.new(name, kind) + local self = tablepool.fetch(pool_name, 0, 16) + self.start_time = get_time() + self.name = name + self.kind = kind + self.status = nil + self.dead = false + return setmetatable(self, mt) +end + + +function _M.append_child(self, child_id) + if not self.child_ids then + self.child_ids = table.new(10, 0) + end + table.insert(self.child_ids, child_id) +end + + +function _M.set_parent(self, parent_id) + self.parent_id = parent_id +end + + +function _M.release(self) + tablepool.release(pool_name, self) +end + + +function _M.set_status(self, code, message) + code = span_status.validate(code) + local status = self.status + if not status then + status = { + code = code, + message = "" + } + self.status = status + else + status.code = code + end + + if code == span_status.ERROR then + status.message = message + end +end + + +function _M.set_attributes(self, ...) + local count = select('#', ...) + for i = 1, count do + local attr = select(i, ...) + table.insert(self.attributes, attr) + end +end Review Comment: `set_attributes` appends into `self.attributes`, but `attributes` is never initialized in `new()`. This will throw on first use. Initialize `self.attributes` (and clear it on reuse) before inserting. ########## apisix/plugins/opentelemetry.lua: ########## @@ -376,48 +384,96 @@ function _M.rewrite(conf, api_ctx) ngx_var.opentelemetry_span_id = span_context.span_id end + if not ctx:span():is_recording() and ngx.ctx.tracing then + ngx.ctx.tracing.skip = true + end + api_ctx.otel_context_token = ctx:attach() -- inject trace context into the headers of upstream HTTP request trace_context_propagator:inject(ctx, ngx.req) end -function _M.delayed_body_filter(conf, api_ctx) - if api_ctx.otel_context_token and ngx.arg[2] then - local ctx = context:current() - ctx:detach(api_ctx.otel_context_token) - api_ctx.otel_context_token = nil +local function create_child_span(tracer, parent_span_ctx, spans, span) + if not span or span.finished then + return + end + span.finished = true + local new_span_ctx, new_span = tracer:start(parent_span_ctx, span.name, + { + kind = span.kind, + attributes = span.attributes, + }) + new_span.start_time = span.start_time + + for _, idx in ipairs(span.child_ids or {}) do + create_child_span(tracer, new_span_ctx, spans, spans[idx]) + end + if span.status then + new_span:set_status(span.status.code, span.status.message) + end + new_span:finish(span.end_time) +end - -- get span from current context - local span = ctx:span() - local upstream_status = core.response.get_upstream_status(api_ctx) - if upstream_status and upstream_status >= 500 then - span:set_status(span_status.ERROR, - "upstream response status: " .. upstream_status) - end - span:set_attributes(attr.int("http.status_code", upstream_status)) +local function inject_core_spans(root_span_ctx, api_ctx, conf) + local tracing = api_ctx.ngx_ctx.tracing + if not tracing then + return + end - span:finish() + local span = root_span_ctx:span() + + local metadata = plugin.plugin_metadata(plugin_name) + local plugin_info = metadata.value + if span and not span:is_recording() then + return + end + local inject_conf = { + sampler = { + name = "always_on", + options = conf.sampler.options + }, + additional_attributes = conf.additional_attributes, + additional_header_prefix_attributes = conf.additional_header_prefix_attributes + } + local tracer, err = core.lrucache.plugin_ctx(lrucache, api_ctx, nil, + create_tracer_obj, inject_conf, plugin_info) + if not tracer then + core.log.error("failed to fetch tracer object: ", err) + return + end + + if #tracing.spans == 0 then + return + end + span.start_time = tracing.spans[1].start_time + local root_span = tracing.root_span + local spans = tracing.spans + for _, idx in ipairs(root_span.child_ids or {}) do + create_child_span(tracer, root_span_ctx, spans, spans[idx]) end end --- body_filter maybe not called because of empty http body response --- so we need to check if the span has finished in log phase function _M.log(conf, api_ctx) if api_ctx.otel_context_token then -- ctx:detach() is not necessary, because of ctx is stored in ngx.ctx local upstream_status = core.response.get_upstream_status(api_ctx) -- get span from current context - local span = context:current():span() + local ctx = context:current() + local span = ctx:span() if upstream_status and upstream_status >= 500 then span:set_status(span_status.ERROR, "upstream response status: " .. upstream_status) end + inject_core_spans(ctx, api_ctx, conf) + span:set_attributes(attr.int("http.status_code", upstream_status), + attr.int("http.response.status_code", upstream_status)) + update_time() Review Comment: `inject_core_spans()` can traverse/export spans that haven't been finished yet. In log phase, `apisix.phase.log.plugins.opentelemetry` (created by `plugin.run_plugin`) is still active when this runs, so `span.end_time` is nil and the exported timing can be wrong (and may break if `new_span:finish()` doesn't accept nil). Consider skipping spans without `end_time`, or restructuring so injection happens after the wrapper span is finished. ########## apisix/init.lua: ########## @@ -901,6 +916,9 @@ function _M.http_header_filter_phase() end core.response.set_header("Apisix-Plugins", core.table.concat(deduplicate, ", ")) end + tracer.finish(ngx_ctx, span) + + tracer.start(ngx_ctx, "apisix.phase.body_filter", tracer.kind.server) end Review Comment: `apisix.phase.body_filter` span is started in `http_header_filter_phase()` but never explicitly finished in `http_body_filter_phase()`. It currently gets closed by `tracer.finish_all()` at the start of log phase, which makes the span duration include time outside body_filter and makes timings less accurate. Prefer finishing the body_filter span at the end of `http_body_filter_phase()` (while keeping the fallback for empty bodies if needed). -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: [email protected] For queries about this service, please contact Infrastructure at: [email protected]
