Improve tracing

1) Add possibility to use HTTP OTLP exporter.
2) Improve tracing so that module creates internal or client span depending if the request is handled by nginx directly or passed upstream.
3) Set span status depending on result. If status code is between 400 - 599 set status as error.
4) Catch internal processing failures in log phase.
5) Rewrite tests in JS

Author: tiithansen

.github/workflows/nginx.yml

@@ -99,12 +99,17 @@ jobs:
           rm -rf /tmp/buildx-cache/nginx
           mv /tmp/buildx-cache/express-new /tmp/buildx-cache/express
           mv /tmp/buildx-cache/nginx-new /tmp/buildx-cache/nginx
-      - name: run tests
+      #- name: run tests
+      #  run: |
+      #    cd instrumentation/nginx/test/instrumentation
+      #    mix test
+      - name: Setup node
+        uses: actions/setup-node@v2
+        with:
+          node-version: '18'
+      - name: Install dependencies
         run: |
           cd instrumentation/nginx/test/instrumentation
-          mix local.hex --force --if-missing
-          mix local.rebar --force --if-missing
-          mix deps.get
           mix test
       - name: copy artifacts
         id: artifacts

instrumentation/nginx/CMakeLists.txt

@@ -23,6 +23,8 @@ add_library(otel_ngx_module SHARED
   src/otel_ngx_module_modules.c
   src/propagate.cpp
   src/script.cpp
+  src/post_batch_span_processor.cpp
+  src/post_span_processor.cpp
 )
 
 target_compile_options(otel_ngx_module

instrumentation/nginx/src/otel_ngx_module.cpp

@@ -21,6 +21,8 @@ extern ngx_module_t otel_ngx_module;
 #include "nginx_config.h"
 #include "nginx_utils.h"
 #include "propagate.h"
+#include "post_span_processor.h"
+#include "post_batch_span_processor.h"
 #include <opentelemetry/context/context.h>
 #include <opentelemetry/nostd/shared_ptr.h>
 #include <opentelemetry/sdk/trace/batch_span_processor.h>
@@ -38,6 +40,7 @@ extern ngx_module_t otel_ngx_module;
 #include <opentelemetry/exporters/otlp/otlp_http_exporter.h>
 
 namespace trace = opentelemetry::trace;
+namespace common = opentelemetry::common;
 namespace nostd = opentelemetry::nostd;
 namespace sdktrace = opentelemetry::sdk::trace;
 namespace otlp = opentelemetry::exporter::otlp;
@@ -134,6 +137,8 @@ static ngx_int_t OtelGetContextVar(ngx_http_request_t*, ngx_http_variable_value_
   return NGX_OK;
 }
 
+
+
 static ngx_int_t
 OtelGetTraceContextVar(ngx_http_request_t* req, ngx_http_variable_value_t* v, uintptr_t data);
 
@@ -496,21 +501,13 @@ TraceContext* CreateTraceContext(ngx_http_request_t* req, ngx_http_variable_valu
   return context;
 }
 
-ngx_int_t StartNgxSpan(ngx_http_request_t* req) {
-  if (!IsOtelEnabled(req)) {
-    return NGX_DECLINED;
-  }
-
-  // Internal requests must be called from another location in nginx, that should already have a trace. Without this check, a call would generate an extra (unrelated) span without much information
-  if (req->internal) {
-    return NGX_DECLINED;
-  }
+TraceContext* StartNgxTrace(ngx_http_request_t* req) {
 
   ngx_http_variable_value_t* val = ngx_http_get_indexed_variable(req, otel_ngx_variables[0].index);
 
   if (!val) {
     ngx_log_error(NGX_LOG_ERR, req->connection->log, 0, "Unable to find OpenTelemetry context");
-    return NGX_DECLINED;
+    return nullptr;
   }
 
   TraceContext* context = CreateTraceContext(req, val);
@@ -524,30 +521,43 @@ ngx_int_t StartNgxSpan(ngx_http_request_t* req) {
     incomingContext = ExtractContext(&carrier);
   }
 
-  trace::StartSpanOptions startOpts;
-  startOpts.kind = trace::SpanKind::kServer;
-  startOpts.parent = GetCurrentSpan(incomingContext);
+  const auto operationName = GetOperationName(req);
 
-  context->request_span = GetTracer()->StartSpan(
-    GetOperationName(req),
-    {
-      {"http.method", FromNgxString(req->method_name)},
-      {"http.flavor", NgxHttpFlavor(req)},
-      {"http.target", FromNgxString(req->unparsed_uri)},
-    },
-    startOpts);
+  std::initializer_list<std::pair<nostd::string_view, common::AttributeValue>> commonAttributes = {
+          {"http.method", FromNgxString(req->method_name)},
+          {"http.flavor", NgxHttpFlavor(req)},
+          {"http.target", FromNgxString(req->unparsed_uri)},
+          // Add http.route as its according to OpenTelemetry spec
+          {"http.route", FromNgxString(req->unparsed_uri)}
+  };
+
+  trace::StartSpanOptions requestStartOpts;
+  requestStartOpts.parent = GetCurrentSpan(incomingContext);
+  requestStartOpts.kind = trace::SpanKind::kServer;
+  context->request_span = GetTracer()->StartSpan(operationName,commonAttributes, requestStartOpts);
+
+  trace::StartSpanOptions innerSpanOpts;
+  innerSpanOpts.parent = context->request_span->GetContext();
+  innerSpanOpts.kind = trace::SpanKind::kInternal;
+
+  context->inner_span = GetTracer()->StartSpan(operationName,commonAttributes,innerSpanOpts);
 
   nostd::string_view serverName = GetNgxServerName(req);
   if (!serverName.empty()) {
     context->request_span->SetAttribute("http.server_name", serverName);
+    context->inner_span->SetAttribute("http.server_name", serverName);
   }
 
   if (req->headers_in.host) {
-    context->request_span->SetAttribute("http.host", FromNgxString(req->headers_in.host->value));
+    const auto host = FromNgxString(req->headers_in.host->value);
+    context->request_span->SetAttribute("http.host", host);
+    context->inner_span->SetAttribute("http.host", host);
   }
 
   if (req->headers_in.user_agent) {
-    context->request_span->SetAttribute("http.user_agent", FromNgxString(req->headers_in.user_agent->value));
+    const auto userAgent = FromNgxString(req->headers_in.user_agent->value);
+    context->request_span->SetAttribute("http.user_agent", userAgent);
+    context->inner_span->SetAttribute("http.user_agent", userAgent);
   }
 
   if (locConf->captureHeaders) {
@@ -559,10 +569,24 @@ ngx_int_t StartNgxSpan(ngx_http_request_t* req) {
                        {excludedHeaders, 2});
   }
 
-  auto outgoingContext = incomingContext.SetValue(trace::kSpanKey, context->request_span);
+  auto outgoingContext = incomingContext.SetValue(trace::kSpanKey, context->inner_span);
 
   InjectContext(&carrier, outgoingContext);
 
+  return context;
+}
+
+ngx_int_t StartNgxSpan(ngx_http_request_t* req) {
+  if (!IsOtelEnabled(req)) {
+    return NGX_DECLINED;
+  }
+
+  if (req->internal) {
+    return NGX_DECLINED;
+  }
+
+  StartNgxTrace(req);
+
   return NGX_DECLINED;
 }
 
@@ -591,10 +615,7 @@ void AddScriptAttributes(
   }
 }
 
-ngx_int_t FinishNgxSpan(ngx_http_request_t* req) {
-  if (!IsOtelEnabled(req)) {
-    return NGX_DECLINED;
-  }
+void UpdateSpan(nostd::shared_ptr<opentelemetry::trace::Span> span, ngx_http_request_t* req, bool captureHeaders = false) {
 
   TraceContext* context = GetTraceContext(req);
 
@@ -603,31 +624,22 @@ ngx_int_t FinishNgxSpan(ngx_http_request_t* req) {
   }
 
   auto span = context->request_span;
-  const auto status_code = req->headers_out.status;
-  span->SetAttribute("http.status_code", status_code);
-
-  if (status_code >= 500) {
-    span->SetStatus(trace::StatusCode::kError);
-  } else {
-    span->SetStatus(trace::StatusCode::kOk);
-  }
+  UpdateSpan(span, req, true);
 
-  OtelNgxLocationConf* locConf = GetOtelLocationConf(req);
+  if (context->inner_span) {
 
-  if (locConf->captureHeaders) {
-    OtelCaptureHeaders(span, ngx_string("http.response.header."), &req->headers_out.headers,
-#if (NGX_PCRE)
-                       locConf->sensitiveHeaderNames, locConf->sensitiveHeaderValues,
-#endif
-                       {});
-  }
+    const bool hasUpstream = req->upstream != nullptr;
+    if (hasUpstream) {
+      context->inner_span->SetAttribute("span.kind", static_cast<int>(trace::SpanKind::kClient));
+    }
 
-  AddScriptAttributes(span.get(), GetOtelMainConf(req)->scriptAttributes, req);
-  AddScriptAttributes(span.get(), locConf->customAttributes, req);
+    UpdateSpan(context->inner_span, req);
 
-  span->UpdateName(GetOperationName(req));
+    context->inner_span->End();
+  }
 
   span->End();
+
   return NGX_DECLINED;
 }
 
@@ -642,7 +654,7 @@ static ngx_int_t InitModule(ngx_conf_t* conf) {
 
   const PhaseHandler handlers[] = {
     {NGX_HTTP_REWRITE_PHASE, StartNgxSpan},
-    {NGX_HTTP_LOG_PHASE, FinishNgxSpan},
+    {NGX_HTTP_LOG_PHASE, FinishNgxSpan}
   };
 
   for (const PhaseHandler& ph : handlers) {
@@ -1292,6 +1304,7 @@ static std::unique_ptr<sdktrace::SpanExporter> CreateExporter(const OtelNgxAgent
 
 static std::unique_ptr<sdktrace::SpanProcessor>
 CreateProcessor(const OtelNgxAgentConfig* conf, std::unique_ptr<sdktrace::SpanExporter> exporter) {
+
   if (conf->processor.type == OtelProcessorBatch) {
     sdktrace::BatchSpanProcessorOptions opts;
     opts.max_queue_size = conf->processor.batch.maxQueueSize;
@@ -1300,11 +1313,11 @@ CreateProcessor(const OtelNgxAgentConfig* conf, std::unique_ptr<sdktrace::SpanEx
     opts.max_export_batch_size = conf->processor.batch.maxExportBatchSize;
 
     return std::unique_ptr<sdktrace::SpanProcessor>(
-      new sdktrace::BatchSpanProcessor(std::move(exporter), opts));
+      new PostBatchSpanProcessor(std::move(exporter), opts));
   }
 
   return std::unique_ptr<sdktrace::SpanProcessor>(
-    new sdktrace::SimpleSpanProcessor(std::move(exporter)));
+    new PostSpanProcessor(std::move(exporter)));
 }
 
 static std::unique_ptr<sdktrace::Sampler> CreateSampler(const OtelNgxAgentConfig* conf) {

instrumentation/nginx/src/post_batch_span_processor.cpp

@@ -0,0 +1,8 @@
+#include "post_batch_span_processor.h"
+#include <opentelemetry/exporters/otlp/otlp_recordable.h>
+
+void PostBatchSpanProcessor::OnEnd(std::unique_ptr<opentelemetry::sdk::trace::Recordable> &&span) noexcept
+{
+  ProxyRecordable* proxy = static_cast<ProxyRecordable*>(span.get());
+  BatchSpanProcessor::OnEnd(std::move(proxy->GetRealRecordable()));
+}

instrumentation/nginx/src/post_batch_span_processor.h

@@ -0,0 +1,27 @@
+#ifndef OPENTELEMETRY_NGINX_POST_BATCH_SPAN_PROCESSOR_H
+#define OPENTELEMETRY_NGINX_POST_BATCH_SPAN_PROCESSOR_H
+
+#include "proxy_recordable.h"
+#include <opentelemetry/nostd/shared_ptr.h>
+#include <opentelemetry/sdk/trace/batch_span_processor.h>
+
+namespace trace = opentelemetry::trace;
+namespace nostd = opentelemetry::nostd;
+namespace sdktrace = opentelemetry::sdk::trace;
+
+class PostBatchSpanProcessor : public sdktrace::BatchSpanProcessor {
+public:
+
+    explicit PostBatchSpanProcessor(std::unique_ptr<sdktrace::SpanExporter> &&exporter,
+                                    const sdktrace::BatchSpanProcessorOptions &options) noexcept
+            : BatchSpanProcessor(std::move(exporter), options)
+    {}
+
+    void OnEnd(std::unique_ptr<opentelemetry::sdk::trace::Recordable> &&span) noexcept override;
+
+    std::unique_ptr<opentelemetry::sdk::trace::Recordable> MakeRecordable() noexcept override {
+      return std::unique_ptr<ProxyRecordable>(new ProxyRecordable());
+    }
+};
+
+#endif //OPENTELEMETRY_NGINX_POST_BATCH_SPAN_PROCESSOR_H

instrumentation/nginx/src/post_span_processor.cpp

@@ -0,0 +1,8 @@
+#include "post_span_processor.h"
+
+void PostSpanProcessor::OnEnd(std::unique_ptr<opentelemetry::sdk::trace::Recordable> &&span) noexcept
+{
+  ProxyRecordable* proxy = static_cast<ProxyRecordable*>(span.get());
+  SimpleSpanProcessor::OnEnd(std::move(proxy->GetRealRecordable()));
+}
+

instrumentation/nginx/src/post_span_processor.h

@@ -0,0 +1,26 @@
+#ifndef OPENTELEMETRY_NGINX_POST_SPAN_PROCESSOR_H
+#define OPENTELEMETRY_NGINX_POST_SPAN_PROCESSOR_H
+
+#include <opentelemetry/nostd/shared_ptr.h>
+#include <opentelemetry/sdk/trace/simple_processor.h>
+#include "proxy_recordable.h"
+
+namespace trace = opentelemetry::trace;
+namespace nostd = opentelemetry::nostd;
+namespace sdktrace = opentelemetry::sdk::trace;
+
+class PostSpanProcessor : public sdktrace::SimpleSpanProcessor {
+public:
+
+    explicit PostSpanProcessor(std::unique_ptr<sdktrace::SpanExporter> &&exporter) noexcept
+    : SimpleSpanProcessor(std::move(exporter))
+    {}
+
+    void OnEnd(std::unique_ptr<opentelemetry::sdk::trace::Recordable> &&span) noexcept override;
+
+    std::unique_ptr<opentelemetry::sdk::trace::Recordable> MakeRecordable() noexcept override {
+      return std::unique_ptr<ProxyRecordable>(new ProxyRecordable());
+    }
+};
+
+#endif //OPENTELEMETRY_NGINX_POST_SPAN_PROCESSOR_H