Tempo flipping boolean attributes from spans and storing wrong value

[lucasoares]

Describe the bug I have an application sending trace data to Tempo and I notice few spans showing a wrong attribute value in Tempo's traces panel. It was randomly showing true for few attributes that I was sure the application exported as false.

To debug it I setup an otel-collector with a logging exporter and otlp exporter to redirect trace data to tempo's distributor. For a specific span in the otel-collector perspective (logging exporter) the attribute is false, but Tempo shows it as true.

This is hapenning very often and I have many spans with incorrect boolean attributes. The problem is not only in the rendering since querying a TraceQL also brings inconsistent results.

Example:

• Collector logging exporter output for the 7aad586c4a5b9745 span:

  Trace ID       : dbb8c655e765f513cf9c94a075bdca6e
  Parent ID      : 
  ID             : 7aad586c4a5b9745
  Name           : /session/v2/token
  Kind           : Server
  Start time     : 2023-04-14 20:35:45.831936 +0000 UTC
  End time       : 2023-04-14 20:35:46.276436871 +0000 UTC
  Status code    : Unset
  Status message : 
  Attributes:
   -> net.transport: Str(ip_tcp)
   -> REDACTED
   -> net.peer.port: Int(43981)
   -> has_passkey: Bool(false)
   -> http.flavor: Str(1.1)
   -> has_authorization: Bool(false)
   -> REDACTED
   -> http.target: Str(/session/v2/token)
   -> http.request_content_length: Int(81)
   -> http.client_ip: Str(REDACTED)
   -> http.host: Str(REDACTED)
   -> net.peer.ip: Str(REDACTED)
   -> thread.name: Str(http-nio-4795-exec-8)
   -> http.route: Str(/session/v2/token)
   -> REDACTED
   -> http.status_code: Int(200)
   -> thread.id: Int(47)
   -> is_internal: Bool(false)
   -> http.scheme: Str(https)
   -> http.method: Str(POST)

• Tempo traces panel for the same 7aad586c4a5b9745 span:

• Search using this attribute as query and many spans are returned from it, proving it is not being flipped only when requested/rendered:

• The search is also inconsistent when searching for false values, with true values being returned:

  The table doesn't show it as true but when I enter on the span it is true. Even more weird, right?

This is not hapenning only for this has_passkey attribute, I saw it hapenning with other boolean attributes I have.

To Reproduce

I honestly don't know how to reproduce it because it is really random. Sometimes it is correct, sometimes it is not.

I also only looked for some boolean attributes I have, I didn't look for non-boolean attributes and now I'm really afraid of the consistency of the Tempo's data in general.

Expected behavior

Attributes should be consistent.

Environment:

• Infrastructure: Kubernetes
• Deployment tool: Helm
• Kubernetes version: 1.24.10-gke.2300
• Node pool machine type: e2-standard-8 (GCP)
• Image type: Container-Optimized OS with containerd (cos_containerd)
• Result of cat /proc/cpuinfo inside any Tempo pod (x86_64 architecture):

  vendor_id   : AuthenticAMD
  cpu family  : 23
  model       : 49
  model name  : AMD EPYC 7B12
  stepping    : 0
  microcode   : 0xffffffff
  cpu MHz     : 2249.998
  cache size  : 512 KB
  physical id : 0
  siblings    : 8
  core id     : 0
  cpu cores   : 4
  apicid      : 0
  initial apicid  : 0
  fpu     : yes
  fpu_exception   : yes
  cpuid level : 13
  wp      : yes
  flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt pdpe1gb rdtscp lm constant_tsc rep_good nopl nonstop_tsc cpuid extd_apicid tsc_known_freq pni pclmulqdq ssse3 fma cx16 sse4_1 sse4_2 movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm cmp_legacy cr8_legacy abm sse4a misalignsse 3dnowprefetch osvw topoext ssbd ibrs ibpb stibp vmmcall fsgsbase tsc_adjust bmi1 avx2 smep bmi2 rdseed adx smap clflushopt clwb sha_ni xsaveopt xsavec xgetbv1 clzero xsaveerptr arat npt nrip_save umip rdpid
  bugs        : sysret_ss_attrs null_seg spectre_v1 spectre_v2 spec_store_bypass retbleed
  bogomips    : 4499.99
  TLB size    : 3072 4K pages
  clflush size    : 64
  cache_alignment : 64
  address sizes   : 48 bits physical, 48 bits virtual

Additional Context

Slack thread we talked about this issue: https://grafana.slack.com/archives/C01D981PEE5/p1681506001786699

We are using Tempo's parquet and GCS as backend for storage.

[joe-elliott]

Thank you for this issue. I have now been able to reproduce it using the otel-cli. It only seems to occur if you have multiple booleans in the same span some of which are true and some of which are false.

This does not repro the issue:

otel-cli exec --service my-service --name "curl google" curl https://google.com --attrs b=false,c=false,d=false,e=false

This does:

otel-cli exec --service my-service --name "curl google" curl https://google.com --attrs b=false,c=false,d=true,e=false

I have seen attributes b, c and e occassionally be set to true. I will continue to dig on this.

[joe-elliott]

This is an issue with our parquet-go library. We are actively working on it: https://github.com/segmentio/parquet-go/issues/501

[joe-elliott]

We have filed a fix based on my understanding of the issue:

https://github.com/segmentio/parquet-go/pull/503

Let's see what the maintainers say.