profile: in-process SIGPROF sampler + exclusive route/phase census (L77); closes to 0.1%
Opt-in (L77 build + --linux77-profile; compiled out by default, 0.02% handler cost). FI/TN cost account closes against direct grid-fill timing within 0.15% (LOD0-2 bins within 1.4%). Passage carving = 66% of LOD0-2 CPU (52-54% whole view), passage support 10-14%, base packed + analytic field ~3%. Hotspots: value noise 17%, lower_bound in VisitNearestPassageSpatialNode 14%, ApplyResolvedStratePassageCarves 6.5%. LOD0/1 complete LAST (4.1/4.6 s) while LOD2 is ready at 2.2 s. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016dhxM43dnWvUu2B5Ph1iG1
This commit is contained in:
1 parent
68cba5a51d
commit
5e091d254c
14 files changed
+1205
-8
No files matched your search
@@ -0,0 +1,257 @@
|
||||
#define _GNU_SOURCE 1
|
||||
#include "VoxelForgeCore/Linux77Profiler.h"
|
||||
|
||||
#if defined(VF_L77_PROFILE)
|
||||
|
||||
#include <algorithm>
|
||||
#include <atomic>
|
||||
#include <cerrno>
|
||||
#include <cinttypes>
|
||||
#include <cstdio>
|
||||
#include <cstdlib>
|
||||
#include <mutex>
|
||||
#include <signal.h>
|
||||
#include <csignal>
|
||||
#include <sys/resource.h>
|
||||
#include <sys/syscall.h>
|
||||
#include <time.h>
|
||||
#include <ucontext.h>
|
||||
#include <unistd.h>
|
||||
#include <pthread.h>
|
||||
|
||||
namespace VoxelForgeCore::Linux77Profiler
|
||||
{
|
||||
namespace
|
||||
{
|
||||
constexpr std::uint32_t Capacity=1u<<20;
|
||||
constexpr std::size_t MaxRegisteredThreads=32;
|
||||
struct FSample
|
||||
{
|
||||
std::uintptr_t pc=0;
|
||||
std::uint8_t lod=0xff,route=0,stage=0,phase=0,halo=0,weight=1;
|
||||
};
|
||||
static_assert(std::atomic<std::uint32_t>::is_always_lock_free);
|
||||
static_assert(std::atomic<std::uint64_t>::is_always_lock_free);
|
||||
std::array<FSample,Capacity> Samples{};
|
||||
std::atomic<std::uint32_t> NextSample{0};
|
||||
std::atomic<std::uint64_t> LostSamples{0},HandlerSamples{0},HandlerNanoseconds{0};
|
||||
std::atomic<std::uint64_t> ExpandedTicks{0};
|
||||
std::atomic<bool> Enabled{false};
|
||||
volatile sig_atomic_t TimerActive=0;
|
||||
std::atomic<std::uint32_t> ActiveHandlers{0};
|
||||
std::uint32_t PeriodMicroseconds=1000;
|
||||
std::mutex TimerRegistryMutex;
|
||||
std::array<timer_t,MaxRegisteredThreads> ThreadTimers{};
|
||||
std::array<pid_t,MaxRegisteredThreads> ThreadIds{};
|
||||
std::array<clockid_t,MaxRegisteredThreads> ThreadCpuClockIds{};
|
||||
std::array<std::uint64_t,MaxRegisteredThreads> ThreadCpuStartNanoseconds{};
|
||||
std::array<std::uint64_t,MaxRegisteredThreads> ThreadProfileCpuNanoseconds{};
|
||||
std::array<std::atomic<std::uint64_t>,MaxRegisteredThreads> ThreadSampleCounts{};
|
||||
std::size_t ThreadTimerCount=0;
|
||||
inline thread_local bool ThreadTimerRegistered=false;
|
||||
std::atomic<std::uint64_t> TimerOverruns{0};
|
||||
|
||||
std::uint64_t ThreadCpuNanoseconds() noexcept
|
||||
{
|
||||
timespec time{};
|
||||
if(clock_gettime(CLOCK_THREAD_CPUTIME_ID,&time)!=0)return 0;
|
||||
return static_cast<std::uint64_t>(time.tv_sec)*1000000000ull
|
||||
+static_cast<std::uint64_t>(time.tv_nsec);
|
||||
}
|
||||
std::uint64_t UserCpuNanoseconds(const timeval& value) noexcept
|
||||
{
|
||||
return static_cast<std::uint64_t>(value.tv_sec)*1000000000ull
|
||||
+static_cast<std::uint64_t>(value.tv_usec)*1000ull;
|
||||
}
|
||||
void SigprofHandler(int, siginfo_t* information, void* context) noexcept
|
||||
{
|
||||
if(!TimerActive)return;
|
||||
ActiveHandlers.fetch_add(1,std::memory_order_relaxed);
|
||||
const std::uint64_t start=ThreadCpuNanoseconds();
|
||||
HandlerSamples.fetch_add(1,std::memory_order_relaxed);
|
||||
const int timerIndex=information?information->si_value.sival_int:-1;
|
||||
if(timerIndex>=0&&static_cast<std::size_t>(timerIndex)<MaxRegisteredThreads)
|
||||
{
|
||||
ThreadSampleCounts[static_cast<std::size_t>(timerIndex)].fetch_add(
|
||||
1,std::memory_order_relaxed);
|
||||
if(information&&information->si_overrun>0)
|
||||
TimerOverruns.fetch_add(static_cast<std::uint64_t>(information->si_overrun),
|
||||
std::memory_order_relaxed);
|
||||
}
|
||||
const std::uint32_t index=NextSample.fetch_add(1,std::memory_order_relaxed);
|
||||
const std::uint64_t overrun=information&&information->si_overrun>0
|
||||
?static_cast<std::uint64_t>(information->si_overrun):0;
|
||||
const std::uint8_t weight=static_cast<std::uint8_t>(
|
||||
std::min<std::uint64_t>(255,overrun+1));
|
||||
ExpandedTicks.fetch_add(weight,std::memory_order_relaxed);
|
||||
if(index<Capacity)
|
||||
{
|
||||
std::uintptr_t pc=0;
|
||||
#if defined(__x86_64__) && defined(REG_RIP)
|
||||
if(context)
|
||||
pc=static_cast<std::uintptr_t>(
|
||||
static_cast<ucontext_t*>(context)->uc_mcontext.gregs[REG_RIP]);
|
||||
#endif
|
||||
const FThreadContext& tag=CurrentContext;
|
||||
Samples[index]={pc,tag.lod,static_cast<std::uint8_t>(tag.route),
|
||||
static_cast<std::uint8_t>(tag.stage),
|
||||
static_cast<std::uint8_t>(tag.phase),static_cast<std::uint8_t>(tag.halo),weight};
|
||||
}
|
||||
else LostSamples.fetch_add(1,std::memory_order_relaxed);
|
||||
const std::uint64_t end=ThreadCpuNanoseconds();
|
||||
if(end>=start)HandlerNanoseconds.fetch_add(end-start,std::memory_order_relaxed);
|
||||
ActiveHandlers.fetch_sub(1,std::memory_order_relaxed);
|
||||
}
|
||||
}
|
||||
|
||||
bool IsEnabled() noexcept{return Enabled.load(std::memory_order_relaxed);}
|
||||
void SetEnabled(bool enabled) noexcept{Enabled.store(enabled,std::memory_order_relaxed);}
|
||||
|
||||
void RegisterThread()
|
||||
{
|
||||
if(ThreadTimerRegistered||!IsEnabled())return;
|
||||
std::lock_guard<std::mutex> lock(TimerRegistryMutex);
|
||||
if(ThreadTimerRegistered||!IsEnabled()||ThreadTimerCount>=MaxRegisteredThreads)return;
|
||||
struct sigevent event{};
|
||||
event.sigev_notify=SIGEV_THREAD_ID;
|
||||
event.sigev_signo=SIGPROF;
|
||||
event.sigev_value.sival_int=static_cast<int>(ThreadTimerCount);
|
||||
event._sigev_un._tid=static_cast<int>(syscall(SYS_gettid));
|
||||
timer_t timer{};
|
||||
if(timer_create(CLOCK_THREAD_CPUTIME_ID,&event,&timer)!=0)
|
||||
{
|
||||
std::fprintf(stderr,"[L77SamplerError] action=thread_timer_create errno=%d\n",errno);
|
||||
return;
|
||||
}
|
||||
itimerspec interval{};
|
||||
interval.it_value.tv_nsec=static_cast<long>(PeriodMicroseconds%1000000u)*1000l;
|
||||
interval.it_value.tv_sec=static_cast<time_t>(PeriodMicroseconds/1000000u);
|
||||
interval.it_interval=interval.it_value;
|
||||
const std::size_t timerIndex=ThreadTimerCount;
|
||||
clockid_t threadCpuClock{};
|
||||
if(pthread_getcpuclockid(pthread_self(),&threadCpuClock)!=0)
|
||||
{
|
||||
timer_delete(timer);
|
||||
std::fprintf(stderr,"[L77SamplerError] action=thread_clock errno=%d\n",errno);
|
||||
return;
|
||||
}
|
||||
timespec threadCpuStart{};
|
||||
if(clock_gettime(threadCpuClock,&threadCpuStart)!=0)
|
||||
{
|
||||
timer_delete(timer);
|
||||
std::fprintf(stderr,"[L77SamplerError] action=thread_clock_read errno=%d\n",errno);
|
||||
return;
|
||||
}
|
||||
ThreadCpuClockIds[timerIndex]=threadCpuClock;
|
||||
ThreadCpuStartNanoseconds[timerIndex]=
|
||||
static_cast<std::uint64_t>(threadCpuStart.tv_sec)*1000000000ull
|
||||
+static_cast<std::uint64_t>(threadCpuStart.tv_nsec);
|
||||
ThreadIds[timerIndex]=static_cast<pid_t>(event._sigev_un._tid);
|
||||
if(timer_settime(timer,0,&interval,nullptr)!=0)
|
||||
{
|
||||
timer_delete(timer);
|
||||
std::fprintf(stderr,"[L77SamplerError] action=thread_timer_start errno=%d\n",errno);
|
||||
return;
|
||||
}
|
||||
ThreadTimers[ThreadTimerCount++]=timer;
|
||||
ThreadTimerRegistered=true;
|
||||
}
|
||||
|
||||
void Start(std::uint32_t periodMicroseconds)
|
||||
{
|
||||
if(TimerActive)return;
|
||||
PeriodMicroseconds=periodMicroseconds?periodMicroseconds:1000;
|
||||
NextSample.store(0,std::memory_order_relaxed);
|
||||
LostSamples.store(0,std::memory_order_relaxed);
|
||||
HandlerSamples.store(0,std::memory_order_relaxed);
|
||||
HandlerNanoseconds.store(0,std::memory_order_relaxed);
|
||||
ExpandedTicks.store(0,std::memory_order_relaxed);
|
||||
TimerOverruns.store(0,std::memory_order_relaxed);
|
||||
struct sigaction action{};
|
||||
action.sa_sigaction=&SigprofHandler;
|
||||
action.sa_flags=SA_SIGINFO|SA_RESTART;
|
||||
sigemptyset(&action.sa_mask);
|
||||
if(sigaction(SIGPROF,&action,nullptr)!=0)
|
||||
{
|
||||
std::fprintf(stderr,"[L77SamplerError] action=install errno=%d\n",errno);
|
||||
return;
|
||||
}
|
||||
SetEnabled(true);
|
||||
TimerActive=1;
|
||||
RegisterThread();
|
||||
std::printf("[L77Sampler] action=start method=thread_cpu_timer period_us=%u capacity=%u\n",
|
||||
PeriodMicroseconds,Capacity);
|
||||
}
|
||||
|
||||
void StopAndPrint()
|
||||
{
|
||||
if(!TimerActive)return;
|
||||
SetEnabled(false);
|
||||
std::size_t registeredThreadCount=0;
|
||||
std::uint64_t profiledThreadCpuNanoseconds=0;
|
||||
{
|
||||
std::lock_guard<std::mutex> lock(TimerRegistryMutex);
|
||||
registeredThreadCount=ThreadTimerCount;
|
||||
for(std::size_t index=0;index<ThreadTimerCount;++index)
|
||||
{
|
||||
itimerspec stopped{};
|
||||
timer_settime(ThreadTimers[index],0,&stopped,nullptr);
|
||||
timespec now{};
|
||||
if(clock_gettime(ThreadCpuClockIds[index],&now)==0)
|
||||
{
|
||||
const std::uint64_t elapsed=static_cast<std::uint64_t>(now.tv_sec)
|
||||
*1000000000ull+static_cast<std::uint64_t>(now.tv_nsec)
|
||||
-ThreadCpuStartNanoseconds[index];
|
||||
ThreadProfileCpuNanoseconds[index]=elapsed;
|
||||
profiledThreadCpuNanoseconds+=elapsed;
|
||||
}
|
||||
timer_delete(ThreadTimers[index]);
|
||||
}
|
||||
ThreadTimerCount=0;
|
||||
}
|
||||
TimerActive=0;
|
||||
while(ActiveHandlers.load(std::memory_order_relaxed)!=0){}
|
||||
rusage usage{};
|
||||
getrusage(RUSAGE_SELF,&usage);
|
||||
const std::uint64_t userNs=UserCpuNanoseconds(usage.ru_utime);
|
||||
const std::uint64_t systemNs=UserCpuNanoseconds(usage.ru_stime);
|
||||
const std::uint32_t stored=std::min(NextSample.load(std::memory_order_relaxed),Capacity);
|
||||
const std::uint64_t handlerCount=HandlerSamples.load(std::memory_order_relaxed);
|
||||
const std::uint64_t handlerNs=HandlerNanoseconds.load(std::memory_order_relaxed);
|
||||
const std::uint64_t expandedTicks=ExpandedTicks.load(std::memory_order_relaxed);
|
||||
std::printf("[L77Sampler] action=stop samples=%u handlers=%llu expanded_ticks=%llu lost=%llu timer_overruns=%llu timer_threads=%zu requested_period_us=%u profiled_thread_cpu_s=%.6f whole_process_cpu_s=%.6f handler_cpu_ms=%.3f handler_share_pct=%.3f observed_us_per_tick=%.3f status=%s\n",
|
||||
stored,static_cast<unsigned long long>(handlerCount),
|
||||
static_cast<unsigned long long>(expandedTicks),
|
||||
static_cast<unsigned long long>(LostSamples.load(std::memory_order_relaxed)),
|
||||
static_cast<unsigned long long>(TimerOverruns.load(std::memory_order_relaxed)),
|
||||
registeredThreadCount,PeriodMicroseconds,
|
||||
static_cast<double>(profiledThreadCpuNanoseconds)/1.0e9,
|
||||
static_cast<double>(userNs+systemNs)/1.0e9,
|
||||
static_cast<double>(handlerNs)/1.0e6,
|
||||
profiledThreadCpuNanoseconds?100.0*static_cast<double>(handlerNs)
|
||||
/static_cast<double>(profiledThreadCpuNanoseconds):0.0,
|
||||
expandedTicks?static_cast<double>(profiledThreadCpuNanoseconds)
|
||||
/static_cast<double>(expandedTicks)/1000.0:0.0,
|
||||
stored>0&&handlerCount>0?"PASS":"NO_SAMPLES");
|
||||
for(std::size_t index=0;index<registeredThreadCount;++index)
|
||||
std::printf("[L77ThreadTimer] index=%zu tid=%d cpu_ms=%.3f samples=%llu\n",index,
|
||||
static_cast<int>(ThreadIds[index]),
|
||||
static_cast<double>(ThreadProfileCpuNanoseconds[index])/1.0e6,
|
||||
static_cast<unsigned long long>(ThreadSampleCounts[index].load(
|
||||
std::memory_order_relaxed)));
|
||||
for(std::uint32_t index=0;index<stored;++index)
|
||||
{
|
||||
const FSample& sample=Samples[index];
|
||||
const auto route=static_cast<ERoute>(sample.route);
|
||||
const auto stage=static_cast<EStage>(sample.stage);
|
||||
const auto phase=static_cast<EPhase>(sample.phase);
|
||||
std::printf("[L77Sample] pc=0x%" PRIxPTR " lod=%u stage=%s route=%s phase=%s halo=%u weight=%u\n",
|
||||
sample.pc,static_cast<unsigned>(sample.lod),StageName(stage),
|
||||
RouteName(route),PhaseName(phase),static_cast<unsigned>(sample.halo),
|
||||
static_cast<unsigned>(sample.weight));
|
||||
}
|
||||
std::fflush(stdout);
|
||||
}
|
||||
}
|
||||
|
||||
#endif
|
||||
Reference in new issue
Block a user