Skip to content

~OpenTelemetrySpanHolder(): Assertion `thread.thread_trace_context.span_id == span_id' failed. #39122

@qoega

Description

@qoega
clickhouse: ../src/Interpreters/OpenTelemetrySpanLog.cpp:114: DB::OpenTelemetrySpanHolder::~OpenTelemetrySpanHolder(): Assertion `thread.thread_trace_context.span_id == span_id' failed.
Process 1401882 stopped
* thread #3, name = 'TCPHandler', stop reason = hit program assert
    frame #4: 0x0000000026b6f113 clickhouse`DB::OpenTelemetrySpanHolder::~OpenTelemetrySpanHolder(this=0x00007fff141cf470) at OpenTelemetrySpanLog.cpp:114:9
(lldb) bt
* thread #3, name = 'TCPHandler', stop reason = hit program assert
    frame #0: 0x00007ffff7ddb03b libc.so.6`raise + 203
    frame #1: 0x00007ffff7dba859 libc.so.6`abort + 299
    frame #2: 0x00007ffff7dba729 libc.so.6`___lldb_unnamed_symbol2384 + 15
    frame #3: 0x00007ffff7dcc006 libc.so.6`__assert_fail + 70
  * frame #4: 0x0000000026b6f113 clickhouse`DB::OpenTelemetrySpanHolder::~OpenTelemetrySpanHolder(this=0x00007fff141cf470) at OpenTelemetrySpanLog.cpp:114:9
    frame #5: 0x0000000026f40d2b clickhouse`std::__1::default_delete<DB::OpenTelemetrySpanHolder>::operator(this=0x00007fff173ef0b8, __ptr=0x00007fff141cf470)(DB::OpenTelemetrySpanHolder*) const at unique_ptr.h:54:5
    frame #6: 0x0000000026f40c1c clickhouse`std::__1::unique_ptr<DB::OpenTelemetrySpanHolder, std::__1::default_delete<DB::OpenTelemetrySpanHolder> >::reset(this=0x00007fff173ef0b8, __p=0x0000000000000000) at unique_ptr.h:315:7
    frame #7: 0x0000000026f3dfd9 clickhouse`std::__1::unique_ptr<DB::OpenTelemetrySpanHolder, std::__1::default_delete<DB::OpenTelemetrySpanHolder> >::~unique_ptr(this=0x00007fff173ef0b8) at unique_ptr.h:269:19
    frame #8: 0x0000000026f2b5b2 clickhouse`DB::executeQueryImpl(begin="OPTIMIZE TABLE simple FINAL", end="", context=std::__1::shared_ptr<DB::Context>::element_type @ 0x00007ffe96e61000 strong=3 weak=7, internal=false, stage=Complete, istr=0x0000000000000000) at executeQuery.cpp:695:13
    frame #9: 0x0000000026f27ec4 clickhouse`DB::executeQuery(query="OPTIMIZE TABLE simple FINAL", context=std::__1::shared_ptr<DB::Context>::element_type @ 0x00007ffe96e61000 strong=3 weak=7, internal=false, stage=Complete) at executeQuery.cpp:1082:30
    frame #10: 0x0000000027f8ba22 clickhouse`DB::TCPHandler::runImpl(this=0x00007fff1145ec00) at TCPHandler.cpp:332:24
    frame #11: 0x0000000027f9ac25 clickhouse`DB::TCPHandler::run(this=0x00007fff1145ec00) at TCPHandler.cpp:1804:9
    frame #12: 0x000000002c4908b9 clickhouse`Poco::Net::TCPServerConnection::start(this=0x00007fff1145ec00) at TCPServerConnection.cpp:43:3
    frame #13: 0x000000002c4910c6 clickhouse`Poco::Net::TCPServerDispatcher::run(this=0x00007fff1144ce00) at TCPServerDispatcher.cpp:115:20
    frame #14: 0x000000002c6d6414 clickhouse`Poco::PooledThread::run(this=0x00007ffff702e200) at ThreadPool.cpp:199:14
    frame #15: 0x000000002c6d2f9a clickhouse`Poco::(anonymous namespace)::RunnableHolder::run(this=0x00007ffff7001390) at Thread.cpp:55:11
    frame #16: 0x000000002c6d1d7e clickhouse`Poco::ThreadImpl::runnableEntry(pThread=0x00007ffff702e238) at Thread_POSIX.cpp:345:27
    frame #17: 0x00007ffff7f92609 libpthread.so.0`start_thread(arg=<unavailable>) at pthread_create.c:477:8
    frame #18: 0x00007ffff7eb7163 libc.so.6`__clone + 67
frame #4: 0x0000000026b6f113 clickhouse`DB::OpenTelemetrySpanHolder::~OpenTelemetrySpanHolder(this=0x00007fff141cf470) at OpenTelemetrySpanLog.cpp:114:9
(lldb) p *this
(DB::OpenTelemetrySpanHolder) $3 = {
  DB::OpenTelemetrySpan = {
    trace_id = {
      t = {
        items = ([0] = 1982251683631061641, [1] = 12176040641251827830)
      }
    }
    span_id = 3937884993496686277
    parent_span_id = 6257233249094713134
    operation_name = "DB::InterpreterOptimizeQuery::execute()"
    start_time_us = 1657620589197672
    finish_time_us = 11936128518282651045
    attributes = {
      DB::FieldVector = size=0 {}
    }
    is_ready = true
  }
}
$4 = {
  thread_id = 1401894
  os_thread_priority = 0
  performance_counters = {
    counters = 0x00007fff11401a00
    counters_holder = std::__1::atomic<unsigned long> @ 0x00007fff11401a00 {
      __value_ = 0x00007fff11401a00
    }
    parent = 0x00007fff0ff5e440
    level = Thread
  }
  memory_tracker = {
    amount = {
      Value = 0
    }
    peak = {
      Value = 0
    }
    soft_limit = {
      Value = 0
    }
    hard_limit = {
      Value = 0
    }
    profiler_limit = {
      Value = 0
    }
    profiler_step = 0
    fault_probability = 0
    sample_probability = 0
    parent = {
      Value = 0x00007fff0ff5e460
    }
    metric = {
      Value = 92
    }
    description_ptr = "(for thread)" {
      Value = 0x000000000e39c777 "(for thread)"
    }
    max_wait_time = {
      Value = (__rep_ = 0)
    }
    overcommit_tracker = {
      Value = nullptr
    }
    log_peak_memory_usage_in_destructor = true
    level = Thread
  }
  untracked_memory = -1062496
  untracked_memory_limit = 4194304
  progress_in = {
    read_rows = {
      Value = 0
    }
    read_bytes = {
      Value = 0
    }
    total_rows_to_read = {
      Value = 0
    }
    total_bytes_to_read = {
      Value = 0
    }
    written_rows = {
      Value = 0
    }
    written_bytes = {
      Value = 0
    }
  }
  progress_out = {
    read_rows = {
      Value = 0
    }
    read_bytes = {
      Value = 0
    }
    total_rows_to_read = {
      Value = 0
    }
    total_bytes_to_read = {
      Value = 0
    }
    written_rows = {
      Value = 0
    }
    written_bytes = {
      Value = 0
    }
  }
  deleter = {
    __f_ = {
      __buf_ = (__small = "\xc0\xd8\xde&\0\0\0\0\U00000001\0\0\0\0\0\0", __large = 0x0000000026ded8c0)
      __invoker_ = {
        __call_ = 0x0000000026df4d40 (clickhouse`void std::__1::__function::__policy_invoker<void ()>::__call_impl<std::__1::__function::__default_alloc_func<void (*)(), void ()> >(std::__1::__function::__policy_storage const*) at function.h:707)
      }
      __policy_ = 0x00000000308a3038
    }
  }
  thread_trace_context = {
    trace_id = {
      t = {
        items = ([0] = 1982251683631061641, [1] = 12176040641251827830)
      }
    }
    span_id = 7545194022923541792
    tracestate = ""
    trace_flags = 0x01 u8'\U00000001'
  }
  thread_group = std::__1::shared_ptr<DB::ThreadGroupStatus>::element_type @ 0x00007fff0ff5e418 strong=2 weak=1 {
    __ptr_ = 0x00007fff0ff5e418
  }
  thread_state = {
    Value = 1
  }
  global_context = std::__1::weak_ptr<const DB::Context>::element_type @ 0x00007ffff717b000 strong=5 weak=128 {
    __ptr_ = 0x00007ffff717b000
  }
  query_context = std::__1::weak_ptr<const DB::Context>::element_type @ 0x00007ffe96e61000 strong=3 weak=7 {
    __ptr_ = 0x00007ffe96e61000
  }
  query_id = "89da3f62-675f-421b-b6e0-88a873fcf9a8"
  logs_queue_ptr = std::__1::weak_ptr<DB::InternalTextLogsQueue>::element_type @ 0x00007fff1144c118 strong=1 weak=3 {
    __ptr_ = 0x00007fff1144c118
  }
  profile_queue_ptr = std::__1::weak_ptr<ConcurrentBoundedQueue<DB::Block> >::element_type @ 0x00007ffef39f9558 strong=1 weak=3 {
    __ptr_ = 0x00007ffef39f9558
  }
  performance_counters_finalized = false
  query_start_time_nanoseconds = 1657620589196915000
  query_start_time_microseconds = 1657620589196915
  query_start_time = 1657620589
  queries_started = 3198
  query_profiler_real = DB::QueryProfilerReal @ 0x00007fff13200a60 {
    __value_ = 0x00007fff13200a60
  }
  query_profiler_cpu = DB::QueryProfilerCPU @ 0x00007fff14119b40 {
    __value_ = 0x00007fff14119b40
  }
  log = 0x00007ffff703f040
  last_rusage = DB::RUsageCounters @ 0x00007fff1140b120 {
    __value_ = 0x00007fff1140b120
  }
  taskstats = DB::TasksStatsCounters @ 0x00007fff11456480 {
    __value_ = 0x00007fff11456480
  }
  fatal_error_callback = {
    __f_ = {
      __buf_ = (__small = "\0\xecE\U00000011\xff\U0000007f\0\0\0\0\0\0\0\0\0", __large = 0x00007fff1145ec00)
      __invoker_ = {
        __call_ = 0x0000000027f9c440 (clickhouse`void std::__1::__function::__policy_invoker<void ()>::__call_impl<std::__1::__function::__default_alloc_func<DB::TCPHandler::runImpl()::$_2, void ()> >(std::__1::__function::__policy_storage const*) at function.h:707)
      }
      __policy_ = 0x00000000308c9ea8
    }
  }
  query_profiler_enabled = true
}

Metadata

Metadata

Assignees

No one assigned

    Labels

    fuzzProblem found by one of the fuzzerstestingSpecial issue with list of bugs found by CI

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions