open-telemetry/opentelemetry-erlang

dmy-gh

@dmy-gh

I like the "linked span" and would love to make it work.

Tristan Sloughter

@tsloughter

@dmy-gh about links, sorry, I forgot to mention that I found a bug when wirting that test and haven't pushed it yet :(. I will this morning

it wasn't able to handle an undefined TraceState when creating the link

Tristan Sloughter

@tsloughter

I'm working on docs and tests that I hope bring out all these remaining bugs and can then release 1.0 very soon

Tristan Sloughter

@tsloughter

open-telemetry/opentelemetry-erlang#197

should have this merged this morning

dmy-gh

@dmy-gh

Nice, I will try the linked span with the PR

What am I doing wrong when trying to close the parent span for the child span example, which leads me to a never ending parent span?

Tristan Sloughter

@tsloughter

hm, that I'm not sure about yet. it looks right.

updating my test to end it, forgot to have that in there

dmy-gh

@dmy-gh

Ok, thank you again for the help :slight_smile:

Tristan Sloughter

@tsloughter

test works fine, so may be some issue in the exporter pipeline that doesn't show up when using the otel_exporter_pid exporter like the tests do

dmy-gh

@dmy-gh

Your test only creates parent and child span once

I'm having issue on the second function call

Tristan Sloughter

@tsloughter

dmy-gh

@dmy-gh

The "parent" span of the second function call has the "parent" span ID of the first call as a parent

Tristan Sloughter

@tsloughter

so an issue in that case, if you are calling from the same process is you have to manually remove the parent span from the context

ending it only ends it it doesn't make it in-active in the context (pdict)

so using with_span is better for regular code

Tristan Sloughter

@tsloughter

@dmy-gh since the code attaches a context it needs to detach it at the end https://github.com/open-telemetry/opentelemetry-erlang/pull/197/files#diff-a7be571ceeaa7a92cf5b75ac1c269834d65dc2d7ad59ae761e550fc95f5324c6R109

this is all stuff with_span does for you

dmy-gh

@dmy-gh

Ok, I'll read the doc once again on this part as it seems I don't quite understand how contexts work

dmy-gh

@dmy-gh

  def child do
    OpenTelemetry.Tracer.with_span "parent" do
      # start the child and set it to current in an unattached context
      child = Tracer.start_span("child")
      Tracer.set_current_span(child)

      task =
        Task.async(fn ->
          # attach the context with the child span active to this process
          Ctx.attach(Ctx.get_current())

          Process.sleep(2_000)
          return = :ok

          Span.end_span(child)

          return
        end)

      return = Task.await(task)

      Process.sleep(1_000)

      return
    end
  end

Works better this way, thank you :slight_smile:

Tristan Sloughter

@tsloughter

that looks like your child span is being sent current only outside of the Task. if you want to create a context with it attached but that context not be the current processes pdict then you need to pass a context variable to set_current_span

hopefully the docs I'm working on will explain this well..

dmy-gh

@dmy-gh

Ahah, waiting for it so :see_no_evil:

Tristan Sloughter

@tsloughter

attached context are in the pdict, so operating with the Tracer without passing a context variable will act on the pdict

dmy-gh

@dmy-gh

So it should be ctx = Tracer.set_current_span(Ctx.get_current(), child) instead of Tracer.set_current_span(child) and then Ctx.attach(ctx) instead of Ctx.attach(Ctx.get_current())

With this fixed, I added a with_span sub child to test the context propagation and it seems to work, at least in the collector output

I put it one last time, hopping it is the working one:

  def child do
    OpenTelemetry.Tracer.with_span "parent" do
      # start the child and set it to current in an unattached context
      child = Tracer.start_span("child")
      ctx = Tracer.set_current_span(Ctx.get_current(), child)

      task =
        Task.async(fn ->
          # attach the context with the child span active to this process
          Ctx.attach(ctx)

          OpenTelemetry.Tracer.with_span "sub child" do
            Process.sleep(1_000)
          end

          Process.sleep(2_000)
          return = :ok

          Span.end_span(child)

          return
        end)

      return = Task.await(task)

      Process.sleep(1_000)

      return
    end
  end

And the collector ouput:

 2021-02-01T14:15:56.013Z    INFO    loggingexporter/logging_exporter.go:313    TracesExporter    {"#spans": 1}
 2021-02-01T14:15:56.013Z    DEBUG    loggingexporter/logging_exporter.go:352    ResourceSpans #0
 InstrumentationLibrarySpans #0
 InstrumentationLibrary  
 Span #0
     Trace ID       : cb92a6334f872a7f0627252a84343726
     Parent ID      : e9eb3a93a4b906e7
     ID             : 48538a2a12443b3b
     Name           : sub child
     Kind           : SPAN_KIND_INTERNAL
     Start time     : 2021-02-01 14:15:54.09668847 +0000 UTC
     End time       : 2021-02-01 14:15:55.09773665 +0000 UTC
     Status code    : STATUS_CODE_UNSET
     Status message : 

 2021-02-01T14:16:01.018Z    INFO    loggingexporter/logging_exporter.go:313    TracesExporter    {"#spans": 2}
 2021-02-01T14:16:01.018Z    DEBUG    loggingexporter/logging_exporter.go:352    ResourceSpans #0
 InstrumentationLibrarySpans #0
 InstrumentationLibrary  
 Span #0
     Trace ID       : cb92a6334f872a7f0627252a84343726
     Parent ID      : 
     ID             : 7230abc39174d66e
     Name           : parent
     Kind           : SPAN_KIND_INTERNAL
     Start time     : 2021-02-01 14:15:54.096561326 +0000 UTC
     End time       : 2021-02-01 14:15:58.099794929 +0000 UTC
     Status code    : STATUS_CODE_UNSET
     Status message : 
 Span #1
     Trace ID       : cb92a6334f872a7f0627252a84343726
     Parent ID      : 7230abc39174d66e
     ID             : e9eb3a93a4b906e7
     Name           : child
     Kind           : SPAN_KIND_INTERNAL
     Start time     : 2021-02-01 14:15:54.096620217 +0000 UTC
     End time       : 2021-02-01 14:15:57.098743035 +0000 UTC
     Status code    : STATUS_CODE_UNSET
     Status message :

dmy-gh

@dmy-gh

Parent IDs and times seems ok

dmy-gh

@dmy-gh

Still have to detach the context

Tristan Sloughter

@tsloughter

that looks right

dmy-gh

@dmy-gh

I had to do:

current_ctx = Ctx.attach(ctx)
...
Span.end_span(child)
Ctx.detach(current_ctx)

In a similar example with a GenServer.call/3 instead of a Task.

Without it new traces where ok but the first one stacked part of the new ones

It's way easier with the with_span macro

Tristan Sloughter

@tsloughter

the with_span macro does the attaching, ending and detaching

also, with_span can take a context as the first argument. so in some cases you don't need to attach the context, just do Tracer.with_span ctx, name, %{}, do ...

dmy-gh

@dmy-gh

Do you have a use case example for the with_span with a context as the first argument?

In what does it differ from a newly created span that one would want as a child or a linked span?

Tristan Sloughter

@tsloughter

in the async example you have instead of attaching ctx you could pass it to with_span

dmy-gh

@dmy-gh

That's what I wanted to do when I was passing the context to the parent attribute

Switching to this version

Well, it still needs to start the span and set it current but at least it prevents from having to end it and detach it

The link attribute will be more clean :thumbsup:

dmy-gh

@dmy-gh

PR merge, nice :thumbsup:

Even though I now have a link instead of :undefined when calling OpenTelemetry.link/1, I still get an error during the span creation
What I tried differs from the repository test (open-telemetry/opentelemetry-erlang@529039d) as it only uses the with_span macro:

  def link do
    Tracer.with_span "parent" do
      parent = Tracer.current_span_ctx()

      task =
        Task.async(fn ->
          Tracer.with_span "child", %{links: [OpenTelemetry.link(parent)]} do
            :hello
          end
        end)

      Task.await(task)
    end
  end

dmy-gh

@dmy-gh

OpenTelemetry.link(parent) returns {:link, 140973076598678694095226025386297353991, 1148588555666536500, [], :undefined}

The stack trace ends with:

  {:opentelemetry_exporter_trace_service_pb, :is_empty_string, [:undefined],
   [
     file: '/test/deps/opentelemetry_exporter/apps/opentelemetry_exporter/src/opentelemetry_exporter_trace_service_pb.erl',
     line: 928
   ]},

Tristan Sloughter

@tsloughter

oh, issue is in the exporter expecting a string. hm

Where communities thrive

People

Repo info

Activity