Sampling statistics might be miscounting Time?

[YaLTeR]

I'm not sure if I'm looking at this wrong, but it seems to me that Sampling statistics is miscounting the total function time somehow. I've got adw_init() that takes up ~60 ms and calls subdivide_infos() (and the rest of the time the program is idling), but in sampling statistics it tallies up as 1.33 s.

Trace: https://bxt.rs/files/temp/init-fns.tracy

[wolfpld]

The inclusive sample count is accumulated in Worker::UpdateSampleStatisticsImpl() — server/TracyWorker.cpp:7750. For every callstack sample it walks the whole stack and does incl += count once per frame occurrence:

for( uint16_t c=1; c<framesCount; c++ )          // every parent frame
{
    const auto fincl = frames[c];
    for( uint8_t f=0; f<fsz; f++ )               // every inline within it
    {
        auto sym = ...find( frame.symAddr )...;
        sym->second.incl += count;               // <-- counted per occurrence
    }
}

There is no per-sample deduplication of symAddr. So if subdivide_infos is on the stack 20 times in a single sample (recursion), that one sample adds 20 to its inclusive count instead of 1.

So yeah, it does count recursive calls multiple times. Probably shouldn't. I need to think about it.

[wolfpld]

Fixed on master. Both the reported issue, and another issue that made the "with children" counts actually "children exclusive".

Exclusive sample counts match in entry statistics and in symbol view. There are no inclusive counts in entry statistics, definitely should be, as currently the case of "function was entered and called something else" is ignored. In symbol view inclusive counts do not match with statistics, with skew to both sides in different scenarios.

[YaLTeR]

Thanks. The numbers seem to make more sense now. Though, still a bit odd (same trace):