diff --git a/client/TracySysTrace.cpp b/client/TracySysTrace.cpp index 5987cf3c..7e7aef19 100644 --- a/client/TracySysTrace.cpp +++ b/client/TracySysTrace.cpp @@ -39,6 +39,15 @@ struct CSwitch uint32_t reserved; }; +struct ReadyThread +{ + uint32_t threadId; + int8_t adjustReason; + int8_t adjustIncrement; + int8_t flag; + int8_t reserverd; +}; + void EventRecordCallback( PEVENT_RECORD record ) { #ifdef TRACY_ON_DEMAND @@ -46,31 +55,39 @@ void EventRecordCallback( PEVENT_RECORD record ) #endif const auto& hdr = record->EventHeader; - if( hdr.EventDescriptor.Opcode != 36 ) return; + if( hdr.EventDescriptor.Opcode == 36 ) + { + const auto cswitch = (const CSwitch*)record->UserData; - const auto cswitch = (const CSwitch*)record->UserData; + Magic magic; + auto token = GetToken(); + auto& tail = token->get_tail_index(); + auto item = token->enqueue_begin( magic ); + MemWrite( &item->hdr.type, QueueType::ContextSwitch ); + MemWrite( &item->contextSwitch.time, hdr.TimeStamp.QuadPart ); + memcpy( &item->contextSwitch.oldThread, &cswitch->oldThreadId, sizeof( cswitch->oldThreadId ) ); + memcpy( &item->contextSwitch.newThread, &cswitch->newThreadId, sizeof( cswitch->newThreadId ) ); + memset( ((char*)&item->contextSwitch.oldThread)+4, 0, 4 ); + memset( ((char*)&item->contextSwitch.newThread)+4, 0, 4 ); + MemWrite( &item->contextSwitch.cpu, record->BufferContext.ProcessorNumber ); + MemWrite( &item->contextSwitch.reason, cswitch->oldThreadWaitReason ); + MemWrite( &item->contextSwitch.state, cswitch->oldThreadState ); + tail.store( magic + 1, std::memory_order_release ); + } + else if( hdr.EventDescriptor.Opcode == 50 ) + { + const auto rt = (const ReadyThread*)record->UserData; - static_assert( sizeof( record->BufferContext.ProcessorNumber ) == sizeof( uint8_t ), "Bad data size" ); - static_assert( sizeof( cswitch->oldThreadId ) == sizeof( uint32_t ), "Bad data size" ); - static_assert( sizeof( cswitch->newThreadId ) == sizeof( uint32_t ), "Bad data size" ); - static_assert( sizeof( hdr.TimeStamp.QuadPart ) == sizeof( int64_t ), "Bad data size" ); - static_assert( sizeof( cswitch->oldThreadWaitReason ) == sizeof( uint8_t ), "Bad data size" ); - static_assert( sizeof( cswitch->oldThreadState ) == sizeof( uint8_t ), "Bad data size" ); - - Magic magic; - auto token = GetToken(); - auto& tail = token->get_tail_index(); - auto item = token->enqueue_begin( magic ); - MemWrite( &item->hdr.type, QueueType::ContextSwitch ); - MemWrite( &item->contextSwitch.time, hdr.TimeStamp.QuadPart ); - memcpy( &item->contextSwitch.oldThread, &cswitch->oldThreadId, sizeof( cswitch->oldThreadId ) ); - memcpy( &item->contextSwitch.newThread, &cswitch->newThreadId, sizeof( cswitch->newThreadId ) ); - memset( ((char*)&item->contextSwitch.oldThread)+4, 0, 4 ); - memset( ((char*)&item->contextSwitch.newThread)+4, 0, 4 ); - MemWrite( &item->contextSwitch.cpu, record->BufferContext.ProcessorNumber ); - MemWrite( &item->contextSwitch.reason, cswitch->oldThreadWaitReason ); - MemWrite( &item->contextSwitch.state, cswitch->oldThreadState ); - tail.store( magic + 1, std::memory_order_release ); + Magic magic; + auto token = GetToken(); + auto& tail = token->get_tail_index(); + auto item = token->enqueue_begin( magic ); + MemWrite( &item->hdr.type, QueueType::ThreadWakeup ); + MemWrite( &item->threadWakeup.time, hdr.TimeStamp.QuadPart ); + memcpy( &item->threadWakeup.thread, &rt->threadId, sizeof( rt->threadId ) ); + memset( ((char*)&item->threadWakeup.thread)+4, 0, 4 ); + tail.store( magic + 1, std::memory_order_release ); + } } bool SysTraceStart() @@ -91,7 +108,7 @@ bool SysTraceStart() const auto psz = sizeof( EVENT_TRACE_PROPERTIES ) + sizeof( KERNEL_LOGGER_NAME ); s_prop = (EVENT_TRACE_PROPERTIES*)tracy_malloc( psz ); memset( s_prop, 0, sizeof( EVENT_TRACE_PROPERTIES ) ); - s_prop->EnableFlags = EVENT_TRACE_FLAG_CSWITCH; + s_prop->EnableFlags = EVENT_TRACE_FLAG_CSWITCH | EVENT_TRACE_FLAG_DISPATCHER; s_prop->LogFileMode = EVENT_TRACE_REAL_TIME_MODE; s_prop->Wnode.BufferSize = psz; s_prop->Wnode.Flags = WNODE_FLAG_TRACED_GUID; diff --git a/common/TracyQueue.hpp b/common/TracyQueue.hpp index e999bd5e..d5b02465 100644 --- a/common/TracyQueue.hpp +++ b/common/TracyQueue.hpp @@ -57,6 +57,7 @@ enum class QueueType : uint8_t CallstackFrame, SysTimeReport, ContextSwitch, + ThreadWakeup, StringData, ThreadName, CustomStringData, @@ -312,6 +313,12 @@ struct QueueContextSwitch uint8_t state; }; +struct QueueThreadWakeup +{ + int64_t time; + uint64_t thread; +}; + struct QueueHeader { union @@ -358,6 +365,7 @@ struct QueueItem QueueCrashReport crashReport; QueueSysTime sysTime; QueueContextSwitch contextSwitch; + QueueThreadWakeup threadWakeup; }; }; #pragma pack() @@ -416,6 +424,7 @@ static const size_t QueueDataSize[] = { sizeof( QueueHeader ) + sizeof( QueueCallstackFrame ), sizeof( QueueHeader ) + sizeof( QueueSysTime ), sizeof( QueueHeader ) + sizeof( QueueContextSwitch ), + sizeof( QueueHeader ) + sizeof( QueueThreadWakeup ), // keep all QueueStringTransfer below sizeof( QueueHeader ) + sizeof( QueueStringTransfer ), // string data sizeof( QueueHeader ) + sizeof( QueueStringTransfer ), // thread name diff --git a/server/TracyEvent.hpp b/server/TracyEvent.hpp index ac2c0f03..1e5cb831 100644 --- a/server/TracyEvent.hpp +++ b/server/TracyEvent.hpp @@ -235,6 +235,7 @@ enum { CrashEventSize = sizeof( CrashEvent ) }; struct ContextSwitchData { enum : int8_t { NoState = 100 }; + enum : int8_t { Wakeup = -2 }; int64_t Start() const { return int64_t( _start_cpu ) >> 8; } void SetStart( int64_t start ) { assert( start < ( 1ll << 47 ) ); _start_cpu = ( _start_cpu & 0xFF ) | uint64_t( start << 8 ); } @@ -249,6 +250,7 @@ struct ContextSwitchData uint64_t _start_cpu; uint64_t _end_reason_state; + int64_t wakeup; }; enum { ContextSwitchDataSize = sizeof( ContextSwitchData ) }; diff --git a/server/TracyVersion.hpp b/server/TracyVersion.hpp index b8671501..25b75cb8 100644 --- a/server/TracyVersion.hpp +++ b/server/TracyVersion.hpp @@ -7,7 +7,7 @@ namespace Version { enum { Major = 0 }; enum { Minor = 5 }; -enum { Patch = 3 }; +enum { Patch = 4 }; } } diff --git a/server/TracyView.cpp b/server/TracyView.cpp index aa72ba4b..1ac3ae92 100644 --- a/server/TracyView.cpp +++ b/server/TracyView.cpp @@ -2372,43 +2372,62 @@ void View::DrawContextSwitches( const ContextSwitch* ctx, bool hover, double pxn { const bool migration = pit->Cpu() != ev.Cpu(); const auto px0 = std::max( { ( pit->End() - m_zvStart ) * pxns, -10.0, minpx } ); + const auto pxw = std::max( ( ev.wakeup - m_zvStart ) * pxns, -10.0 ); const auto px1 = std::min( ( ev.Start() - m_zvStart ) * pxns, w + 10.0 ); const auto color = migration ? 0xFFEE7711 : 0xFF2222AA; - draw->AddLine( wpos + ImVec2( px0, round( offset + ty * 0.5 ) - 0.5 ), wpos + ImVec2( px1, round( offset + ty * 0.5 ) - 0.5 ), color, 2 ); - - if( hover && ImGui::IsMouseHoveringRect( wpos + ImVec2( px0, offset ), wpos + ImVec2( px1, offset + ty ) ) ) + draw->AddLine( wpos + ImVec2( px0, round( offset + ty * 0.5 ) - 0.5 ), wpos + ImVec2( pxw, round( offset + ty * 0.5 ) - 0.5 ), color, 2 ); + if( ev.wakeup != ev.Start() ) { - ImGui::BeginTooltip(); - TextFocused( "Thread is", migration ? "migrating CPUs" : "waiting" ); - TextFocused( "Waiting time:", TimeToString( ev.Start() - pit->End() ) ); - if( migration ) - { - TextFocused( "CPU:", RealToString( pit->Cpu(), true ) ); - ImGui::SameLine(); -#ifdef TRACY_EXTENDED_FONT - TextFocused( ICON_FA_LONG_ARROW_ALT_RIGHT, RealToString( ev.Cpu(), true ) ); -#else - TextFocused( "->", RealToString( ev.Cpu(), true ) ); -#endif - } - else - { - TextFocused( "CPU:", RealToString( ev.Cpu(), true ) ); - } - if( pit->Reason() != 100 ) - { - TextFocused( "Wait reason:", DecodeContextSwitchReasonCode( pit->Reason() ) ); - ImGui::SameLine(); - TextDisabledUnformatted( DecodeContextSwitchReason( pit->Reason() ) ); - } - TextFocused( "Wait state:", DecodeContextSwitchStateCode( pit->State() ) ); - ImGui::SameLine(); - TextDisabledUnformatted( DecodeContextSwitchState( pit->State() ) ); - ImGui::EndTooltip(); + draw->AddLine( wpos + ImVec2( pxw, round( offset + ty * 0.5 ) - 0.5 ), wpos + ImVec2( px1, round( offset + ty * 0.5 ) - 0.5 ), 0xFF2280A0, 2 ); + } - if( ImGui::IsMouseClicked( 2 ) ) + if( hover ) + { + if( ImGui::IsMouseHoveringRect( wpos + ImVec2( px0, offset ), wpos + ImVec2( pxw, offset + ty ) ) ) { - ZoomToRange( pit->End(), ev.Start() ); + ImGui::BeginTooltip(); + TextFocused( "Thread is", migration ? "migrating CPUs" : "waiting" ); + TextFocused( "Waiting time:", TimeToString( ev.wakeup - pit->End() ) ); + if( migration ) + { + TextFocused( "CPU:", RealToString( pit->Cpu(), true ) ); + ImGui::SameLine(); + #ifdef TRACY_EXTENDED_FONT + TextFocused( ICON_FA_LONG_ARROW_ALT_RIGHT, RealToString( ev.Cpu(), true ) ); + #else + TextFocused( "->", RealToString( ev.Cpu(), true ) ); + #endif + } + else + { + TextFocused( "CPU:", RealToString( ev.Cpu(), true ) ); + } + if( pit->Reason() != 100 ) + { + TextFocused( "Wait reason:", DecodeContextSwitchReasonCode( pit->Reason() ) ); + ImGui::SameLine(); + TextDisabledUnformatted( DecodeContextSwitchReason( pit->Reason() ) ); + } + TextFocused( "Wait state:", DecodeContextSwitchStateCode( pit->State() ) ); + ImGui::SameLine(); + TextDisabledUnformatted( DecodeContextSwitchState( pit->State() ) ); + ImGui::EndTooltip(); + + if( ImGui::IsMouseClicked( 2 ) ) + { + ZoomToRange( pit->End(), ev.wakeup ); + } + } + else if( ev.wakeup != ev.Start() && ImGui::IsMouseHoveringRect( wpos + ImVec2( pxw, offset ), wpos + ImVec2( px1, offset + ty ) ) ) + { + ImGui::BeginTooltip(); + TextFocused( "Thread is", "waking up" ); + TextFocused( "Scheduling delay:", TimeToString( ev.Start() - ev.wakeup ) ); + if( ImGui::IsMouseClicked( 2 ) ) + { + ZoomToRange( pit->End(), ev.wakeup ); + } + ImGui::EndTooltip(); } } } diff --git a/server/TracyWorker.cpp b/server/TracyWorker.cpp index 21719191..a8761478 100644 --- a/server/TracyWorker.cpp +++ b/server/TracyWorker.cpp @@ -1415,7 +1415,17 @@ Worker::Worker( FileRead& f, EventType::Type eventMask ) auto ptr = data->v.data(); for( uint64_t j=0; jSetStart( ReadTimeOffset( f, refTime ) ); + if( fileVer >= FileVersion( 0, 5, 4 ) ) + { + ptr->wakeup = ReadTimeOffset( f, refTime ); + ptr->SetStart( ReadTimeOffset( f, refTime ) ); + } + else + { + int64_t start = ReadTimeOffset( f, refTime ); + ptr->wakeup = start; + ptr->SetStart( start ); + } int64_t diff; f.Read( diff ); if( diff > 0 ) runningTime += diff; @@ -3062,6 +3072,9 @@ bool Worker::Process( const QueueItem& ev ) case QueueType::ContextSwitch: ProcessContextSwitch( ev.contextSwitch ); break; + case QueueType::ThreadWakeup: + ProcessThreadWakeup( ev.threadWakeup ); + break; default: assert( false ); break; @@ -4119,13 +4132,22 @@ void Worker::ProcessContextSwitch( const QueueContextSwitch& ev ) it = m_data.ctxSwitch.emplace( ev.newThread, ctx ).first; } auto& data = it->second->v; - assert( data.empty() || (uint64_t)data.back().End() <= time ); - auto& item = data.push_next(); - item.SetStart( time ); - item.SetEnd( -1 ); - item.SetCpu( ev.cpu ); - item.SetReason( -1 ); - item.SetState( -1 ); + ContextSwitchData* item = nullptr; + if( !data.empty() && data.back().Reason() == ContextSwitchData::Wakeup ) + { + item = &data.back(); + } + else + { + assert( data.empty() || (uint64_t)data.back().End() <= time ); + item = &data.push_next(); + item->wakeup = time; + } + item->SetStart( time ); + item->SetEnd( -1 ); + item->SetCpu( ev.cpu ); + item->SetReason( -1 ); + item->SetState( -1 ); auto& cx = cs.push_next(); cx.SetStart( time ); @@ -4140,6 +4162,28 @@ void Worker::ProcessContextSwitch( const QueueContextSwitch& ev ) } } +void Worker::ProcessThreadWakeup( const QueueThreadWakeup& ev ) +{ + const auto time = TscTime( ev.time - m_data.baseTime ); + m_data.lastTime = std::max( m_data.lastTime, time ); + + auto it = m_data.ctxSwitch.find( ev.thread ); + if( it == m_data.ctxSwitch.end() ) + { + auto ctx = m_slab.AllocInit(); + it = m_data.ctxSwitch.emplace( ev.thread, ctx ).first; + } + auto& data = it->second->v; + if( !data.empty() && data.back().End() < 0 ) return; // wakeup of a running thread + auto& item = data.push_next(); + item.wakeup = time; + item.SetStart( time ); + item.SetEnd( -1 ); + item.SetCpu( 0 ); + item.SetReason( ContextSwitchData::Wakeup ); + item.SetState( -1 ); +} + void Worker::MemAllocChanged( int64_t time ) { const auto val = (double)m_data.memory.usage; @@ -4948,6 +4992,7 @@ void Worker::Write( FileWrite& f ) int64_t refTime = 0; for( auto& cs : ctx->second->v ) { + WriteTimeOffset( f, refTime, cs.wakeup ); WriteTimeOffset( f, refTime, cs.Start() ); WriteTimeOffset( f, refTime, cs.End() ); uint8_t cpu = cs.Cpu(); diff --git a/server/TracyWorker.hpp b/server/TracyWorker.hpp index 606f5b9d..67be1353 100644 --- a/server/TracyWorker.hpp +++ b/server/TracyWorker.hpp @@ -440,6 +440,7 @@ private: tracy_force_inline void ProcessCrashReport( const QueueCrashReport& ev ); tracy_force_inline void ProcessSysTime( const QueueSysTime& ev ); tracy_force_inline void ProcessContextSwitch( const QueueContextSwitch& ev ); + tracy_force_inline void ProcessThreadWakeup( const QueueThreadWakeup& ev ); tracy_force_inline void ProcessZoneBeginImpl( ZoneEvent* zone, const QueueZoneBegin& ev ); tracy_force_inline void ProcessZoneBeginAllocSrcLocImpl( ZoneEvent* zone, const QueueZoneBegin& ev );