diff --git a/CcpTelemetry.cpp b/CcpTelemetry.cpp index 86a0d01..6cfa1c8 100644 --- a/CcpTelemetry.cpp +++ b/CcpTelemetry.cpp @@ -95,6 +95,11 @@ bool CcpTelemetryMemoryTrackingIsEnabled() return s_config.trackMemoryAllocations; } +bool CcpTelemetryLockTrackingIsEnabled() +{ + return s_config.trackLocks; +} + void CcpRegisterMutex( class CcpMutex& m, const char* owner, const char* name ) { // Store the name for future Telemetry sessions, even if we're already connected. @@ -450,6 +455,11 @@ bool CcpTelemetryMemoryTrackingIsEnabled() return false; } +bool CcpTelemetryLockTrackingIsEnabled() +{ + return false; +} + void CcpRegisterThread( CcpThreadId_t threadId, const char* name ) { } diff --git a/include/CcpMutex.h b/include/CcpMutex.h index 5dc60ea..10083c8 100644 --- a/include/CcpMutex.h +++ b/include/CcpMutex.h @@ -3,8 +3,10 @@ #ifndef CCPMUTEX_H #define CCPMUTEX_H -#include "CcpTelemetry.h" +#include + #include "CcpAtomic.h" +#include "CcpTelemetry.h" #ifdef _WIN32 @@ -19,10 +21,9 @@ class CcpMutex m_name = name; #if CCP_TELEMETRY_ENABLED - if ( CcpTelemetryIsConnected() ) - { - TracyCLockAnnounce( m_tracyLockContext ); - } + // Lazily announce on first Acquire/Release; this also handles the case where + // the mutex is created before telemetry is connected. + EnsureTracyLockState(); #endif CcpRegisterMutex( *this, owner, name ); @@ -32,24 +33,29 @@ class CcpMutex { ::DeleteCriticalSection( &m_mutex ); #if CCP_TELEMETRY_ENABLED - if ( m_tracyLockContext ) { + // Only terminate if Lock tracking is turned on, we still have a live context AND telemetry is still connected. + // If telemetry has been disconnected meanwhile, the context is already stale. + if ( CcpTelemetryLockTrackingIsEnabled() && m_tracyLockContext && CcpTelemetryIsConnected() ) + { TracyCLockTerminate( m_tracyLockContext ); } + m_tracyLockContext = nullptr; #endif } void Acquire() { #if CCP_TELEMETRY_ENABLED + EnsureTracyLockState(); bool notifyTracy{false}; - if ( CcpTelemetryIsConnected() && m_tracyLockContext ) + if ( m_tracyLockContext ) { notifyTracy = TracyCLockBeforeLock( m_tracyLockContext ); } #endif EnterCriticalSection( &m_mutex); #if CCP_TELEMETRY_ENABLED - if ( notifyTracy ) + if ( notifyTracy && m_tracyLockContext ) { TracyCLockAfterLock( m_tracyLockContext ); } @@ -60,7 +66,8 @@ class CcpMutex { LeaveCriticalSection( &m_mutex ); #if CCP_TELEMETRY_ENABLED - if ( CcpTelemetryIsConnected() && m_tracyLockContext ) + EnsureTracyLockState(); + if ( m_tracyLockContext ) { TracyCLockAfterUnlock( m_tracyLockContext ); } @@ -82,6 +89,33 @@ class CcpMutex private: #if CCP_TELEMETRY_ENABLED + // Synchronizes m_tracyLockContext with the current telemetry connection state. + // - If Lock tracking is disabled, behave as if telemetry were disconnected. + // - If telemetry is connected, and we don't yet have a context, announce one. + // - If telemetry is disconnected, but we still have a (now stale) context, drop it + // so that a future reconnect will produce a fresh, valid context. + // After this returns, all other Tracy calls in Acquire/Release can rely on a + // single, fast null-check of m_tracyLockContext. + void EnsureTracyLockState() + { + const bool connected = CcpTelemetryLockTrackingIsEnabled() && CcpTelemetryIsConnected(); + if ( m_tracyLockContext ) + { + if ( !connected ) + { + // Telemetry disconnected (or lock tracking disabled); drop the stale + // context quickly so that the next connect produces a fresh announce/name. + m_tracyLockContext = nullptr; + } + } + else if ( connected ) + { + const std::string tracyLockName = std::string( m_owner ? m_owner : "" ) + "-" + ( m_name ? m_name : "" ); + TracyCLockAnnounce( m_tracyLockContext ); + TracyCLockCustomName( m_tracyLockContext, tracyLockName.c_str(), tracyLockName.size() ); + } + } + TracyCLockCtx m_tracyLockContext{nullptr}; #endif CRITICAL_SECTION m_mutex; @@ -112,10 +146,9 @@ class CcpMutex m_name = name; #if CCP_TELEMETRY_ENABLED - if ( CcpTelemetryIsConnected() ) - { - TracyCLockAnnounce( m_tracyLockContext ); - } + // Lazily announce on first Acquire/Release; this also handles the case where + // the mutex is created before telemetry is connected. + EnsureTracyLockState(); #endif CcpRegisterMutex( *this, owner, name ); @@ -125,24 +158,29 @@ class CcpMutex { pthread_mutex_destroy( &m_mutex ); #if CCP_TELEMETRY_ENABLED - if ( m_tracyLockContext ) { + // Only terminate if Lock tracking is turned on, we still have a live context AND telemetry is still connected. + // If telemetry has been disconnected meanwhile, the context is already stale. + if ( CcpTelemetryLockTrackingIsEnabled() && m_tracyLockContext && CcpTelemetryIsConnected() ) + { TracyCLockTerminate( m_tracyLockContext ); } + m_tracyLockContext = nullptr; #endif } void Acquire() { #if CCP_TELEMETRY_ENABLED + EnsureTracyLockState(); bool notifyTracy{false}; - if ( CcpTelemetryIsConnected() && m_tracyLockContext ) + if ( m_tracyLockContext ) { notifyTracy = TracyCLockBeforeLock( m_tracyLockContext ); } #endif pthread_mutex_lock( &m_mutex); #if CCP_TELEMETRY_ENABLED - if ( notifyTracy ) + if ( notifyTracy && m_tracyLockContext ) { TracyCLockAfterLock( m_tracyLockContext ); } @@ -153,7 +191,8 @@ class CcpMutex { pthread_mutex_unlock( &m_mutex ); #if CCP_TELEMETRY_ENABLED - if ( CcpTelemetryIsConnected() && m_tracyLockContext ) + EnsureTracyLockState(); + if ( m_tracyLockContext ) { TracyCLockAfterUnlock( m_tracyLockContext ); } @@ -175,6 +214,25 @@ class CcpMutex private: #if CCP_TELEMETRY_ENABLED + // See the Windows variant above for documentation. + void EnsureTracyLockState() + { + const bool connected = CcpTelemetryLockTrackingIsEnabled() && CcpTelemetryIsConnected(); + if ( m_tracyLockContext ) + { + if ( !connected ) + { + m_tracyLockContext = nullptr; + } + } + else if ( connected ) + { + const std::string tracyLockName = std::string( m_owner ? m_owner : "" ) + "-" + ( m_name ? m_name : "" ); + TracyCLockAnnounce( m_tracyLockContext ); + TracyCLockCustomName( m_tracyLockContext, tracyLockName.c_str(), tracyLockName.size() ); + } + } + TracyCLockCtx m_tracyLockContext{nullptr}; #endif pthread_mutex_t m_mutex; diff --git a/include/CcpTelemetry.h b/include/CcpTelemetry.h index 670bfcf..c3b3150 100644 --- a/include/CcpTelemetry.h +++ b/include/CcpTelemetry.h @@ -45,6 +45,7 @@ struct CcpTelemetryConfig std::string applicationName; std::chrono::milliseconds captureDuration{}; bool trackMemoryAllocations{false}; + bool trackLocks{false}; }; [[deprecated( "Use `CcpStartTelemetry( const CcpTelemetryConfig& config ) instead" )]] CARBON_CORE_API bool CcpStartTelemetry( const char* server, int connectionType, uint32_t maxThreadCount ); @@ -69,6 +70,7 @@ CARBON_CORE_API bool CcpTelemetryIsConnected(); CARBON_CORE_API bool CcpTelemetryIsStarted(); CARBON_CORE_API bool CcpTelemetryIsStopped(); CARBON_CORE_API bool CcpTelemetryMemoryTrackingIsEnabled(); +CARBON_CORE_API bool CcpTelemetryLockTrackingIsEnabled(); CARBON_CORE_API void CcpTelemetrySetActiveFiber( const std::string& name ); CARBON_CORE_API const std::string& CcpTelemetryGetActiveFiber(); diff --git a/tests/CcpTelemetry.cpp b/tests/CcpTelemetry.cpp index b675be4..d9d8ee8 100644 --- a/tests/CcpTelemetry.cpp +++ b/tests/CcpTelemetry.cpp @@ -2,8 +2,13 @@ #include +#include +#include +#include #include #include +#include +#include #include @@ -62,11 +67,13 @@ class CcpTelemetryTest : public ::testing::Test void StartTelemetry( std::string appName = "Telemetry Tests", std::chrono::milliseconds duration = std::chrono::milliseconds::zero(), - bool trackMemory = false ) + bool trackMemory = true, + bool trackLocks = true ) { CcpTelemetryConfig conf{ appName }; conf.captureDuration = duration; conf.trackMemoryAllocations = trackMemory; + conf.trackLocks = trackLocks; CcpStartTelemetry( conf ); // It may appear weird that this checks `TracyIsStarted`, but the reason is that the internal state machine // in CcpTelemetry only advances to `CcpTelemetryIsStarted` once it _also_ has established a connection to @@ -129,6 +136,53 @@ class CcpTelemetryTest : public ::testing::Test return tracyZones.end() != std::find_if( tracyZones.begin(), tracyZones.end(), pred ); } + // Helper for Raw lock tests, finding lock announced via TracyCLockAnnounce at a given line. + // Locks are identified by their announce call site because absolute lock ids and announce counts + // are not stable across tests: Tracy defers LockAnnounce/LockTerminate events and replays them + // on every new connection, so locks from earlier tests reappear here. + // For the same reason, when several locks match the call site (e.g. when a test is repeated + // within one process), the most recently announced one wins. + // Call it as a TickTelemetry predicate. + bool TryGetLockAtLine( uint32_t line, TracyTestClient::LockInfo& outLock ) + { + bool found = false; + for( const auto& lock : m_tracyClient.GetAllLocks() ) + { + // All tests are in this file, hence lock.source == __FILE__ + if( lock.line == line && lock.source == __FILE__ && ( !found || lock.id > outLock.id ) ) + { + outLock = lock; + found = true; + } + } + return found; + } + + // Helper for CcpMutex tests, finding active locks by the given custom name. + // CcpMutex names its lock "-" via EnsureTracyLockState helper function. + // Name arrives async shortly after announce event, call function from a TickTelemetry predicate. + // When a test is repeated within one process, Tracy replays earlier (terminated) locks having + // the same name, where the most recently announced lock wins by id. + bool TryGetActiveLockNamed( const std::string& name, TracyTestClient::LockInfo& outLock ) + { + bool found = false; + for( const auto& lock : m_tracyClient.GetActiveLocks() ) + { + if( lock.name == name && ( !found || lock.id > outLock.id ) ) + { + outLock = lock; + found = true; + } + } + return found; + } + + // Refreshes a previously identified lock by id. + bool TryGetLockById( uint32_t lockId, TracyTestClient::LockInfo& outLock ) + { + return m_tracyClient.TryGetLock( lockId, outLock ); + } + const std::string expectedNoFiber; const std::string expectedFiberName1{ "TestFiber1" }; const std::string expectedFiberName2{ "TestFiber2" }; @@ -136,6 +190,7 @@ class CcpTelemetryTest : public ::testing::Test TracyTestClient m_tracyClient; }; + TEST_F( CcpTelemetryTest, TestFiberSwitching ) { CcpTelemetrySetActiveFiber( expectedFiberName1 ); @@ -243,3 +298,435 @@ TEST_F( CcpTelemetryTest, StartStopStartTelemetryWhileClientIsRunning ) EXPECT_TRUE( m_tracyClient.GetZones().empty() ); EXPECT_EQ( 2, m_tracyClient.GetZoneEndCount() ); } + +TEST_F( CcpTelemetryTest, RawTracyLockCounters ) +{ + TracyCLockCtx lockCtx; + TracyTestClient::LockInfo lockInfo; + std::string lockName = "CcpTelemetryTest-RawTracyLockCounters"; + EXPECT_EQ( 0, m_tracyClient.GetLockAnnounceCount() ); + EXPECT_EQ( 0, m_tracyClient.GetLockWaitCount() ); + EXPECT_EQ( 0, m_tracyClient.GetLockObtainCount() ); + EXPECT_EQ( 0, m_tracyClient.GetLockReleaseCount() ); + EXPECT_EQ( 0, m_tracyClient.GetLockTerminateCount() ); + + // Announce Lock: + const uint32_t announceLine = __LINE__ + 1; // The line where we call TracyCLockAnnounce() + TracyCLockAnnounce( lockCtx ); + TickTelemetry( [&] { return TryGetLockAtLine( announceLine, lockInfo ); } ); + EXPECT_EQ( "", lockInfo.name ) << "Name is only set in TracyCLockCustomName"; + EXPECT_EQ( announceLine, lockInfo.line ); + EXPECT_EQ( 1, m_tracyClient.GetLockAnnounceCount() ); + + // Give the Lock a name: + TracyCLockCustomName( lockCtx, lockName.c_str(), lockName.size() ); + TickTelemetry( [&] { return TryGetLockAtLine( announceLine, lockInfo ) && lockInfo.name == lockName; } ); + EXPECT_EQ( lockName, lockInfo.name ); + EXPECT_FALSE( lockInfo.terminated ); + EXPECT_EQ( 0, size(lockInfo.waitingThreads) ); + EXPECT_EQ( 0, lockInfo.waitCount ); + EXPECT_EQ( 0, lockInfo.obtainCount ); + EXPECT_EQ( 0, lockInfo.releaseCount ); + + // Before Lock Acquire: + const auto notifyTracy = TracyCLockBeforeLock( lockCtx ); + TickTelemetry( [&] { return TryGetLockAtLine( announceLine, lockInfo ) && (lockInfo.obtainCount == 1 || lockInfo.waitCount == 1); } ); + EXPECT_TRUE( notifyTracy ); + EXPECT_EQ( 1, lockInfo.waitCount + lockInfo.obtainCount ) << "Sum of Wait+Obtain needs to match"; + EXPECT_EQ( 1, m_tracyClient.GetLockObtainCount() + m_tracyClient.GetLockWaitCount() ) << "Sum of Wait+Obtain needs to match"; + + // After Lock Acquire: + TracyCLockAfterLock( lockCtx ); + TickTelemetry( [&] { return TryGetLockAtLine( announceLine, lockInfo ) && lockInfo.obtainCount == 1; } ); + EXPECT_EQ( 1, lockInfo.waitCount ); + EXPECT_EQ( 1, lockInfo.obtainCount ); + EXPECT_EQ( 0, lockInfo.releaseCount ); + EXPECT_EQ( 1, m_tracyClient.GetLockObtainCount() ); + EXPECT_EQ( 1, m_tracyClient.GetLockWaitCount() ); + + // After Lock Release: + TracyCLockAfterUnlock( lockCtx ); + TickTelemetry( [&] { return TryGetLockAtLine( announceLine, lockInfo ) && lockInfo.releaseCount == 1; } ); + EXPECT_EQ( 1, lockInfo.releaseCount ); + EXPECT_EQ( 1, m_tracyClient.GetLockReleaseCount() ); + + // Remove the Lock: + TracyCLockTerminate( lockCtx ); + TickTelemetry( [&] { return TryGetLockAtLine( announceLine, lockInfo ) && lockInfo.terminated; } ); + EXPECT_TRUE( lockInfo.terminated ); +} + +// A locks, B waits, A unlocks, B locks, B unlocks. +TEST_F( CcpTelemetryTest, RawTracyLockOneWaitingThread ) +{ + TracyCLockCtx lockCtx; + TracyTestClient::LockInfo lockInfo; + std::string lockName = "CcpTelemetryTest-RawTracyLockOneWaitingThread"; + + const uint32_t announceLine = __LINE__ + 1; + TracyCLockAnnounce( lockCtx ); + TracyCLockCustomName( lockCtx, lockName.c_str(), lockName.size() ); + TickTelemetry( [&] { return TryGetLockAtLine( announceLine, lockInfo ) && !lockInfo.terminated; } ); + ASSERT_TRUE( TryGetLockAtLine( announceLine, lockInfo ) ); + + std::mutex mutex; + auto lockMutex = [&] { + const auto notifyTracy = TracyCLockBeforeLock( lockCtx ); + mutex.lock(); + if( notifyTracy ) + { + TracyCLockAfterLock( lockCtx ); + } + }; + auto unlockMutex = [&] { + mutex.unlock(); + TracyCLockAfterUnlock( lockCtx ); + }; + + // Thread A acquires the lock and holds it until we tell it to release. + // The locking must happen on worker threads so that this thread can keep + // ticking the telemetry while the lock is being held / waited on. + std::atomic releaseA{ false }; + std::thread threadA( [&] { + lockMutex(); + while( !releaseA.load() ) + std::this_thread::sleep_for( std::chrono::milliseconds( 1 ) ); + unlockMutex(); + } ); + + TickTelemetry( [&] { return TryGetLockAtLine( announceLine, lockInfo ) && lockInfo.holderThread != 0; } ); + const uint32_t threadAId = lockInfo.holderThread; + EXPECT_NE( 0u, threadAId ); + EXPECT_EQ( 1, lockInfo.waitCount ); + EXPECT_EQ( 1, lockInfo.obtainCount ); + EXPECT_TRUE( lockInfo.waitingThreads.empty() ); + + // Thread B blocks on the lock while A is holding it. + std::thread threadB( [&] { + lockMutex(); + unlockMutex(); + } ); + + TickTelemetry( [&] { return TryGetLockAtLine( announceLine, lockInfo ) && lockInfo.waitingThreads.size() == 1; } ); + EXPECT_EQ( 1u, lockInfo.waitingThreads.size() ); + const uint32_t threadBId = lockInfo.waitingThreads.empty() ? 0 : lockInfo.waitingThreads.front(); + EXPECT_NE( 0u, threadBId ); + EXPECT_NE( threadAId, threadBId ); + EXPECT_EQ( threadAId, lockInfo.holderThread ) << "A should still hold the lock while B waits"; + EXPECT_EQ( 2, lockInfo.waitCount ); + EXPECT_EQ( 1, lockInfo.obtainCount ); + EXPECT_EQ( 0, lockInfo.releaseCount ); + + // Let A unlock; B then obtains and releases the lock. + releaseA.store( true ); + threadA.join(); + threadB.join(); + + TickTelemetry( [&] { return TryGetLockAtLine( announceLine, lockInfo ) && lockInfo.releaseCount == 2; } ); + EXPECT_EQ( 2, lockInfo.waitCount ); + EXPECT_EQ( 2, lockInfo.obtainCount ); + EXPECT_EQ( 2, lockInfo.releaseCount ); + EXPECT_EQ( 0u, lockInfo.holderThread ); + EXPECT_TRUE( lockInfo.waitingThreads.empty() ); + + TracyCLockTerminate( lockCtx ); + TickTelemetry( [&] { return TryGetLockAtLine( announceLine, lockInfo ) && lockInfo.terminated; } ); + EXPECT_TRUE( lockInfo.terminated ); +} + +// A locks, B waits, C waits, A unlocks, B and C lock/unlock in turn. +TEST_F( CcpTelemetryTest, RawTracyLockMultipleWaitingThreads ) +{ + TracyCLockCtx lockCtx; + TracyTestClient::LockInfo lockInfo; + std::string lockName = "CcpTelemetryTest-RawTracyLockMultipleWaitingThreads"; + + const uint32_t announceLine = __LINE__ + 1; + TracyCLockAnnounce( lockCtx ); + TracyCLockCustomName( lockCtx, lockName.c_str(), lockName.size() ); + TickTelemetry( [&] { return TryGetLockAtLine( announceLine, lockInfo ) && !lockInfo.terminated; } ); + ASSERT_TRUE( TryGetLockAtLine( announceLine, lockInfo ) ); + + std::mutex mutex; + auto lockMutex = [&] { + const auto notifyTracy = TracyCLockBeforeLock( lockCtx ); + mutex.lock(); + if( notifyTracy ) + { + TracyCLockAfterLock( lockCtx ); + } + }; + auto unlockMutex = [&] { + mutex.unlock(); + TracyCLockAfterUnlock( lockCtx ); + }; + + std::atomic releaseA{ false }; + std::thread threadA( [&] { + lockMutex(); + while( !releaseA.load() ) + std::this_thread::sleep_for( std::chrono::milliseconds( 1 ) ); + unlockMutex(); + } ); + + TickTelemetry( [&] { return TryGetLockAtLine( announceLine, lockInfo ) && lockInfo.holderThread != 0; } ); + const uint32_t threadAId = lockInfo.holderThread; + EXPECT_NE( 0u, threadAId ); + + // B and C block on the lock one after the other while A is holding it. + auto waiterBody = [&] { + lockMutex(); + unlockMutex(); + }; + std::thread threadB( waiterBody ); + TickTelemetry( [&] { return TryGetLockAtLine( announceLine, lockInfo ) && lockInfo.waitingThreads.size() == 1; } ); + std::thread threadC( waiterBody ); + TickTelemetry( [&] { return TryGetLockAtLine( announceLine, lockInfo ) && lockInfo.waitingThreads.size() == 2; } ); + + EXPECT_EQ( 2u, lockInfo.waitingThreads.size() ); + EXPECT_EQ( threadAId, lockInfo.holderThread ) << "A should still hold the lock while B and C wait"; + EXPECT_EQ( 3, lockInfo.waitCount ); + EXPECT_EQ( 1, lockInfo.obtainCount ); + EXPECT_EQ( 0, lockInfo.releaseCount ); + if( lockInfo.waitingThreads.size() == 2 ) + { + EXPECT_NE( lockInfo.waitingThreads[0], lockInfo.waitingThreads[1] ); + EXPECT_NE( threadAId, lockInfo.waitingThreads[0] ); + EXPECT_NE( threadAId, lockInfo.waitingThreads[1] ); + } + + // Let A unlock; B and C then obtain and release the lock in whichever + // order the OS wakes them up. + releaseA.store( true ); + threadA.join(); + threadB.join(); + threadC.join(); + + TickTelemetry( [&] { return TryGetLockAtLine( announceLine, lockInfo ) && lockInfo.releaseCount == 3; } ); + EXPECT_EQ( 3, lockInfo.waitCount ); + EXPECT_EQ( 3, lockInfo.obtainCount ); + EXPECT_EQ( 3, lockInfo.releaseCount ); + EXPECT_EQ( 0u, lockInfo.holderThread ); + EXPECT_TRUE( lockInfo.waitingThreads.empty() ); + + TracyCLockTerminate( lockCtx ); + TickTelemetry( [&] { return TryGetLockAtLine( announceLine, lockInfo ) && lockInfo.terminated; } ); + EXPECT_TRUE( lockInfo.terminated ); +} + +// --------------------------------------------------------------------------- +// CcpMutex / CcpAutoMutex +// --------------------------------------------------------------------------- +// CcpMutex announces a Tracy lock in the EnsureTracyLockState helper function +// and names it "-" via TracyCLockCustomName. +// It reports wait/obtain around EnterCriticalSection in Acquire(), release in +// Release() and terminates in destructor. +// The custom name is what currently identifies a CcpMutex lock; see TryGetActiveLockNamed. + +TEST_F( CcpTelemetryTest, CcpMutexAnnounceAndTerminate ) +{ + TracyTestClient::LockInfo lockInfo; + + // Scope the CcpMutex so we can see what happens on destruction. + { + std::string lockName = "CcpTelemetryTest-CcpMutexAnnounceAndTerminate"; + CcpMutex mutex( "CcpTelemetryTest", "CcpMutexAnnounceAndTerminate" ); + + // The custom name arrives almost immediately, but the source location + // resolves through extra server-query round trips; wait for both. + TickTelemetry( [&] { return TryGetActiveLockNamed( lockName, lockInfo ) && !lockInfo.source.empty(); } ); + ASSERT_TRUE( TryGetActiveLockNamed( lockName, lockInfo ) ); + EXPECT_FALSE( lockInfo.terminated ); + // The owner and name passed to CcpMutex arrive combined as the custom lock name. + EXPECT_EQ( lockName, lockInfo.name ); + // The announce site is the EnsureTracyLockState helper function + EXPECT_EQ( "EnsureTracyLockState", lockInfo.function ); + EXPECT_EQ( 0u, lockInfo.holderThread ); + EXPECT_TRUE( lockInfo.waitingThreads.empty() ); + EXPECT_EQ( 0, lockInfo.waitCount ); + EXPECT_EQ( 0, lockInfo.obtainCount ); + EXPECT_EQ( 0, lockInfo.releaseCount ); + } + + // Destroying the mutex terminates its lock. + const uint32_t lockId = lockInfo.id; + TickTelemetry( [&] { return TryGetLockById( lockId, lockInfo ) && lockInfo.terminated; } ); + EXPECT_TRUE( lockInfo.terminated ); +} + +TEST_F( CcpTelemetryTest, CcpMutexAcquireAndRelease ) +{ + std::string lockName = "CcpTelemetryTest-CcpMutexAcquireAndRelease"; + CcpMutex mutex( "CcpTelemetryTest", "CcpMutexAcquireAndRelease" ); + + TracyTestClient::LockInfo lockInfo; + TickTelemetry( [&] { return TryGetActiveLockNamed( lockName, lockInfo ); } ); + ASSERT_TRUE( TryGetActiveLockNamed( lockName, lockInfo ) ); + const uint32_t lockId = lockInfo.id; + + mutex.Acquire(); + TickTelemetry( [&] { return TryGetLockById( lockId, lockInfo ) && lockInfo.obtainCount == 1; } ); + EXPECT_EQ( 1, lockInfo.waitCount ); + EXPECT_EQ( 1, lockInfo.obtainCount ); + EXPECT_EQ( 0, lockInfo.releaseCount ); + EXPECT_NE( 0u, lockInfo.holderThread ); + EXPECT_TRUE( lockInfo.waitingThreads.empty() ); + + mutex.Release(); + TickTelemetry( [&] { return TryGetLockById( lockId, lockInfo ) && lockInfo.releaseCount == 1; } ); + EXPECT_EQ( 1, lockInfo.waitCount ); + EXPECT_EQ( 1, lockInfo.obtainCount ); + EXPECT_EQ( 1, lockInfo.releaseCount ); + EXPECT_EQ( 0u, lockInfo.holderThread ); +} + +// A acquires the CcpMutex, B waits, A releases, B acquires and releases. +TEST_F( CcpTelemetryTest, CcpMutexContentionAcrossThreads ) +{ + std::string lockName = "CcpTelemetryTest-CcpMutexContentionAcrossThreads"; + CcpMutex mutex( "CcpTelemetryTest", "CcpMutexContentionAcrossThreads" ); + + TracyTestClient::LockInfo lockInfo; + TickTelemetry( [&] { return TryGetActiveLockNamed( lockName, lockInfo ); } ); + ASSERT_TRUE( TryGetActiveLockNamed( lockName, lockInfo ) ); + const uint32_t lockId = lockInfo.id; + + // Thread A acquires the mutex and holds it until we tell it to release. + // The locking must happen on worker threads so that this thread can keep + // ticking the telemetry while the mutex is being held / waited on. + std::atomic releaseA{ false }; + std::thread threadA( [&] { + mutex.Acquire(); + while( !releaseA.load() ) + std::this_thread::sleep_for( std::chrono::milliseconds( 1 ) ); + mutex.Release(); + } ); + + TickTelemetry( [&] { return TryGetLockById( lockId, lockInfo ) && lockInfo.holderThread != 0; } ); + const uint32_t threadAId = lockInfo.holderThread; + EXPECT_NE( 0u, threadAId ); + EXPECT_EQ( 1, lockInfo.waitCount ); + EXPECT_EQ( 1, lockInfo.obtainCount ); + EXPECT_TRUE( lockInfo.waitingThreads.empty() ); + + // Thread B blocks on the mutex while A is holding it. + std::thread threadB( [&] { + mutex.Acquire(); + mutex.Release(); + } ); + + TickTelemetry( [&] { return TryGetLockById( lockId, lockInfo ) && lockInfo.waitingThreads.size() == 1; } ); + EXPECT_EQ( 1u, lockInfo.waitingThreads.size() ); + const uint32_t threadBId = lockInfo.waitingThreads.empty() ? 0 : lockInfo.waitingThreads.front(); + EXPECT_NE( 0u, threadBId ); + EXPECT_NE( threadAId, threadBId ); + EXPECT_EQ( threadAId, lockInfo.holderThread ) << "A should still hold the mutex while B waits"; + EXPECT_EQ( 2, lockInfo.waitCount ); + EXPECT_EQ( 1, lockInfo.obtainCount ); + EXPECT_EQ( 0, lockInfo.releaseCount ); + + // Let A release; B then acquires and releases the mutex. + releaseA.store( true ); + threadA.join(); + threadB.join(); + + TickTelemetry( [&] { return TryGetLockById( lockId, lockInfo ) && lockInfo.releaseCount == 2; } ); + EXPECT_EQ( 2, lockInfo.waitCount ); + EXPECT_EQ( 2, lockInfo.obtainCount ); + EXPECT_EQ( 2, lockInfo.releaseCount ); + EXPECT_EQ( 0u, lockInfo.holderThread ); + EXPECT_TRUE( lockInfo.waitingThreads.empty() ); +} + +TEST_F( CcpTelemetryTest, CcpAutoMutexScopeLocking ) +{ + std::string lockName = "CcpTelemetryTest-CcpAutoMutexScopeLocking"; + CcpMutex mutex( "CcpTelemetryTest", "CcpAutoMutexScopeLocking" ); + + TracyTestClient::LockInfo lockInfo; + TickTelemetry( [&] { return TryGetActiveLockNamed( lockName, lockInfo ); } ); + ASSERT_TRUE( TryGetActiveLockNamed( lockName, lockInfo ) ); + const uint32_t lockId = lockInfo.id; + + { + CcpAutoMutex autoMutex( mutex ); + + TickTelemetry( [&] { return TryGetLockById( lockId, lockInfo ) && lockInfo.obtainCount == 1; } ); + EXPECT_EQ( 1, lockInfo.waitCount ); + EXPECT_EQ( 1, lockInfo.obtainCount ); + EXPECT_EQ( 0, lockInfo.releaseCount ); + EXPECT_NE( 0u, lockInfo.holderThread ); + } + + TickTelemetry( [&] { return TryGetLockById( lockId, lockInfo ) && lockInfo.releaseCount == 1; } ); + EXPECT_EQ( 1, lockInfo.obtainCount ); + EXPECT_EQ( 1, lockInfo.releaseCount ); + EXPECT_EQ( 0u, lockInfo.holderThread ); +} + +TEST_F( CcpTelemetryTest, CcpAutoMutexEarlyRelease ) +{ + std::string lockName = "CcpTelemetryTest-CcpAutoMutexEarlyRelease"; + CcpMutex mutex( "CcpTelemetryTest", "CcpAutoMutexEarlyRelease" ); + + TracyTestClient::LockInfo lockInfo; + TickTelemetry( [&] { return TryGetActiveLockNamed( lockName, lockInfo ); } ); + ASSERT_TRUE( TryGetActiveLockNamed( lockName, lockInfo ) ); + const uint32_t lockId = lockInfo.id; + + { + CcpAutoMutex autoMutex( mutex ); + + TickTelemetry( [&] { return TryGetLockById( lockId, lockInfo ) && lockInfo.obtainCount == 1; } ); + EXPECT_EQ( 1, lockInfo.obtainCount ); + EXPECT_NE( 0u, lockInfo.holderThread ); + + autoMutex.Release(); + TickTelemetry( [&] { return TryGetLockById( lockId, lockInfo ) && lockInfo.releaseCount == 1; } ); + EXPECT_EQ( 1, lockInfo.releaseCount ); + EXPECT_EQ( 0u, lockInfo.holderThread ); + } + + // Destroying the CcpAutoMutex after the early release must not release the + // mutex a second time. Tick a little longer to give a (faulty) second + // release event a chance to arrive before asserting it did not. + TickTelemetry( nullptr, std::chrono::milliseconds( 100 ) ); + ASSERT_TRUE( TryGetLockById( lockId, lockInfo ) ); + EXPECT_EQ( 1, lockInfo.obtainCount ); + EXPECT_EQ( 1, lockInfo.releaseCount ); +} + +TEST_F( CcpTelemetryTest, MultipleCcpMutexesAnnounceDistinctLocks ) +{ + // The custom lock names make the two mutexes distinguishable even though + // they share the same announce call site in CcpMutex.h. + CcpMutex firstMutex( "CcpTelemetryTest", "MultiTestFirstMutex" ); + CcpMutex secondMutex( "CcpTelemetryTest", "MultiTestSecondMutex" ); + std::string firstLockName = "CcpTelemetryTest-MultiTestFirstMutex"; + std::string secondLockName = "CcpTelemetryTest-MultiTestSecondMutex"; + + // resolved) announce source location, so wait for that to settle too. + TracyTestClient::LockInfo firstLock; + TracyTestClient::LockInfo secondLock; + TickTelemetry( [&] { + return TryGetActiveLockNamed( firstLockName, firstLock ) && + TryGetActiveLockNamed( secondLockName, secondLock ); + } ); + ASSERT_TRUE( TryGetActiveLockNamed( firstLockName, firstLock ) ); + ASSERT_TRUE( TryGetActiveLockNamed( secondLockName, secondLock ) ); + EXPECT_NE( firstLock.id, secondLock.id ); + + // Each mutex drives its own lock: acquiring the second must not affect the first. + secondMutex.Acquire(); + TickTelemetry( [&] { return TryGetLockById( secondLock.id, secondLock ) && secondLock.obtainCount == 1; } ); + EXPECT_EQ( 1, secondLock.obtainCount ); + EXPECT_NE( 0u, secondLock.holderThread ); + ASSERT_TRUE( TryGetLockById( firstLock.id, firstLock ) ); + EXPECT_EQ( 0, firstLock.obtainCount ); + EXPECT_EQ( 0u, firstLock.holderThread ); + + secondMutex.Release(); + TickTelemetry( [&] { return TryGetLockById( secondLock.id, secondLock ) && secondLock.releaseCount == 1; } ); + EXPECT_EQ( 1, secondLock.releaseCount ); + EXPECT_EQ( 0u, secondLock.holderThread ); +} diff --git a/tests/TracyTestClient.cpp b/tests/TracyTestClient.cpp index cfc040f..a2941b6 100644 --- a/tests/TracyTestClient.cpp +++ b/tests/TracyTestClient.cpp @@ -1,6 +1,8 @@ // Copyright © 2025 CCP ehf. #include "TracyTestClient.h" +#include +#include #include #include #include @@ -253,6 +255,38 @@ std::vector TracyTestClient::GetFiberNames() const return names; } +std::vector TracyTestClient::GetAllLocks() const +{ + std::lock_guard lock( m_dataMutex ); + std::vector result; + result.reserve( m_locks.size() ); + for( const auto& [id, info] : m_locks ) + result.push_back( info ); + return result; +} + +std::vector TracyTestClient::GetActiveLocks() const +{ + std::lock_guard lock( m_dataMutex ); + std::vector result; + for( const auto& [id, info] : m_locks ) + { + if( !info.terminated ) + result.push_back( info ); + } + return result; +} + +bool TracyTestClient::TryGetLock( uint32_t id, LockInfo& outLock ) const +{ + std::lock_guard lock( m_dataMutex ); + auto it = m_locks.find( id ); + if( it == m_locks.end() ) + return false; + outLock = it->second; + return true; +} + // --------------------------------------------------------------------------- // Private helpers // --------------------------------------------------------------------------- @@ -325,6 +359,24 @@ TracyTestClient::ZoneStack& TracyTestClient::CurrentStack( uint32_t thread ) return m_threadZoneStacks[thread]; } +TracyTestClient::LockInfo& TracyTestClient::GetOrCreateLockById( uint32_t id ) +{ + auto& info = m_locks[id]; + info.id = id; + return info; +} + +void TracyTestClient::RequestLockString( uint64_t ptr, uint32_t lockId, int field ) +{ + auto& pending = m_pendingLockStrings[ptr]; + // Several locks can share a string pointer (e.g. the source file); query the + // profiler only once per pointer while a reply is outstanding. + const bool alreadyQueried = !pending.empty(); + pending.push_back( { lockId, field } ); + if( !alreadyQueried ) + SendQueryLocked( tracy::ServerQueryString, ptr ); +} + // Parse the decompressed byte stream and update internal state. void TracyTestClient::ProcessDecompressedData( const char* data, int sz ) { @@ -399,6 +451,29 @@ void TracyTestClient::ProcessDecompressedData( const char* data, int sz ) std::lock_guard lock( m_dataMutex ); m_fiberNames[strPtr] = std::move( name ); } + else if( idx == QueueIdx( tracy::QueueType::StringData ) ) + { + // Reply to a ServerQueryString we sent while resolving a + // lock source location; strPtr echoes the queried pointer. + std::lock_guard lock( m_dataMutex ); + auto pendingIt = m_pendingLockStrings.find( strPtr ); + if( pendingIt != m_pendingLockStrings.end() ) + { + const std::string value( ptr, strSz ); + for( const auto& target : pendingIt->second ) + { + auto& info = GetOrCreateLockById( target.lockId ); + switch( target.field ) + { + case 0: info.name = value; break; + case 1: info.function = value; break; + case 2: info.source = value; break; + default: break; + } + } + m_pendingLockStrings.erase( pendingIt ); + } + } ptr += strSz; } @@ -415,6 +490,10 @@ void TracyTestClient::ProcessDecompressedData( const char* data, int sz ) std::memcpy( &strSz, ptr, sizeof( strSz ) ); ptr += sizeof( strSz ); if( ptr + strSz > end ) return; + // Remember the payload: fat-pointer items (e.g. LockName) are + // preceded by a SingleStringData event carrying their string. + if( idx == QueueIdx( tracy::QueueType::SingleStringData ) ) + m_pendingSingleString.assign( ptr, strSz ); ptr += strSz; } else @@ -459,6 +538,88 @@ void TracyTestClient::ProcessDecompressedData( const char* data, int sz ) break; } + case tracy::QueueType::LockAnnounce: + { + m_lockAnnounceCount.fetch_add( 1, std::memory_order_relaxed ); + const uint32_t lockId = item->lockAnnounce.id; + const uint64_t srcloc = item->lockAnnounce.lckloc; + std::lock_guard lock( m_dataMutex ); + GetOrCreateLockById( lockId ); + // Resolve the announce call site. The reply carries no request + // pointer, so remember which lock the next reply belongs to. + m_pendingLockSrcLocs.push_back( lockId ); + SendQueryLocked( tracy::ServerQuerySourceLocation, srcloc ); + break; + } + + case tracy::QueueType::LockTerminate: + { + m_lockTerminateCount.fetch_add( 1, std::memory_order_relaxed ); + std::lock_guard lock( m_dataMutex ); + GetOrCreateLockById( item->lockTerminate.id ).terminated = true; + break; + } + + case tracy::QueueType::LockWait: + { + m_lockWaitCount.fetch_add( 1, std::memory_order_relaxed ); + std::lock_guard lock( m_dataMutex ); + auto& info = GetOrCreateLockById( item->lockWait.id ); + ++info.waitCount; + info.waitingThreads.push_back( item->lockWait.thread ); + break; + } + + case tracy::QueueType::LockObtain: + { + m_lockObtainCount.fetch_add( 1, std::memory_order_relaxed ); + const uint32_t thread = item->lockObtain.thread; + std::lock_guard lock( m_dataMutex ); + auto& info = GetOrCreateLockById( item->lockObtain.id ); + ++info.obtainCount; + info.holderThread = thread; + auto& waiting = info.waitingThreads; + auto waitIt = std::find( waiting.begin(), waiting.end(), thread ); + if( waitIt != waiting.end() ) + waiting.erase( waitIt ); + break; + } + + case tracy::QueueType::LockRelease: + { + m_lockReleaseCount.fetch_add( 1, std::memory_order_relaxed ); + std::lock_guard lock( m_dataMutex ); + auto& info = GetOrCreateLockById( item->lockRelease.id ); + ++info.releaseCount; + info.holderThread = 0; + break; + } + + case tracy::QueueType::LockName: + { + std::lock_guard lock( m_dataMutex ); + GetOrCreateLockById( item->lockName.id ).name = m_pendingSingleString; + break; + } + + case tracy::QueueType::SourceLocation: + { + std::lock_guard lock( m_dataMutex ); + if( !m_pendingLockSrcLocs.empty() ) + { + const uint32_t lockId = m_pendingLockSrcLocs.front(); + m_pendingLockSrcLocs.pop_front(); + GetOrCreateLockById( lockId ).line = item->srcloc.line; + if( item->srcloc.name != 0 ) + RequestLockString( item->srcloc.name, lockId, 0 ); + if( item->srcloc.function != 0 ) + RequestLockString( item->srcloc.function, lockId, 1 ); + if( item->srcloc.file != 0 ) + RequestLockString( item->srcloc.file, lockId, 2 ); + } + break; + } + case tracy::QueueType::FiberEnter: { const uint64_t fiberPtr = item->fiberEnter.fiber; diff --git a/tests/TracyTestClient.h b/tests/TracyTestClient.h index 073216a..99d95fb 100644 --- a/tests/TracyTestClient.h +++ b/tests/TracyTestClient.h @@ -2,6 +2,7 @@ #pragma once #include +#include #include #include #include @@ -26,6 +27,21 @@ class TracyTestClient using ZoneStack = std::vector; + struct LockInfo + { + uint32_t id = 0; + std::string name; // TracyCLockCustomName() or source location (function/source/line) from TracyCLockAnnounce() + std::string function; + std::string source; + uint32_t line = 0; + bool terminated = false; // LockTerminate event was received + uint32_t holderThread = 0; // thread currently holding the lock, 0 = none + std::vector waitingThreads; // threads between LockWait and LockObtain + int waitCount = 0; // LockWait events (TracyCLockBeforeLock) + int obtainCount = 0; // LockObtain events (TracyCLockAfterLock) + int releaseCount = 0; // LockRelease events (TracyCLockAfterUnlock) + }; + TracyTestClient(); ~TracyTestClient(); @@ -35,6 +51,7 @@ class TracyTestClient void Disconnect(); bool IsConnected() const; + // Global counters for ZoneBegin/End states int GetZoneBeginCount() const { return m_zoneBeginCount.load( std::memory_order_relaxed ); } int GetZoneEndCount() const { return m_zoneEndCount.load( std::memory_order_relaxed ); } @@ -47,6 +64,23 @@ class TracyTestClient std::vector GetFiberNames() const; + // Global counters for different internal Lock states (Announce, Wait, Obtain, Release, Terminate). + // Note: LockAnnounce/LockTerminate are deferred items in Tracy, so they are replayed for previously + // announced locks on every new connection. Within a process that runs several tests, these two counters + // therefore also include locks announced before this client connected. + int GetLockAnnounceCount() const { return m_lockAnnounceCount.load( std::memory_order_relaxed ); } + int GetLockTerminateCount() const { return m_lockTerminateCount.load( std::memory_order_relaxed ); } + int GetLockWaitCount() const { return m_lockWaitCount.load( std::memory_order_relaxed ); } + int GetLockObtainCount() const { return m_lockObtainCount.load( std::memory_order_relaxed ); } + int GetLockReleaseCount() const { return m_lockReleaseCount.load( std::memory_order_relaxed ); } + + // Returns all locks this client has seen (including terminated ones). + std::vector GetAllLocks() const; + // Returns all announced locks that have not been terminated yet. + std::vector GetActiveLocks() const; + // Looks up a single lock by its Tracy lock id. + bool TryGetLock( uint32_t id, LockInfo& outLock ) const; + TracyTestClient( const TracyTestClient& ) = delete; TracyTestClient& operator=( const TracyTestClient& ) = delete; @@ -59,9 +93,17 @@ class TracyTestClient // Must be called with m_dataMutex held. ZoneStack& CurrentStack( uint32_t thread ); - // Opaque handles, allocated on heap to keep implementation details out of this header. - void* m_socket = nullptr; // TcpSocket* - void* m_lz4Stream = nullptr; // LZ4_streamDecode_t* + // Returns the LockInfo for the given lock id, creating it if necessary. + // Must be called with m_dataMutex held. + LockInfo& GetOrCreateLockById( uint32_t id ); + + // Queries the string behind ptr from the profiler and routes the reply into + // the given LockInfo field. Must be called with m_dataMutex held. + void RequestLockString( uint64_t ptr, uint32_t lockId, int field ); + + // Opaque handles, allocated on heap to keep implementation details out of this header. + void* m_socket = nullptr; // TcpSocket* + void* m_lz4Stream = nullptr; // LZ4_streamDecode_t* // Ring buffer matching Tracy's decompression scheme (TracyWorker allocates // TargetFrameSize*3 + 1): a write may begin at an offset of up to @@ -75,6 +117,11 @@ class TracyTestClient std::atomic m_shutdown{ false }; std::atomic m_zoneBeginCount{ 0 }; std::atomic m_zoneEndCount{ 0 }; + std::atomic m_lockAnnounceCount{ 0 }; + std::atomic m_lockTerminateCount{ 0 }; + std::atomic m_lockWaitCount{ 0 }; + std::atomic m_lockObtainCount{ 0 }; + std::atomic m_lockReleaseCount{ 0 }; // Current thread established by ThreadContext events (recv thread only, no mutex needed). uint32_t m_currentThread = 0; @@ -87,9 +134,28 @@ class TracyTestClient ZoneInfo m_pendingZone; bool m_hasPendingZone = false; + // Payload of the most recent SingleStringData event, to be consumed by the + // following fat-pointer item (e.g. LockName). Recv thread only. + std::string m_pendingSingleString; + std::unordered_map m_threadCurrentFiber; // thread id → active fiber ptr (0 = none) std::unordered_map m_threadZoneStacks; // thread id → zone stack std::unordered_map m_fiberZoneStacks; // fiber ptr → zone stack std::unordered_map m_fiberNames; // fiber ptr → name std::unordered_set m_queriedFibers; // ptrs already queried + + std::unordered_map m_locks; // lock id → LockInfo state + + // SourceLocation replies carry no request pointer; the profiler answers + // queries in order, so match replies FIFO against the announcing lock ids. + std::deque m_pendingLockSrcLocs; + + // String replies do echo the queried pointer. Several locks may share a + // string (e.g. the source file), so each pointer maps to all destinations. + struct PendingLockString + { + uint32_t lockId; + int field; // 0 = name, 1 = function, 2 = source + }; + std::unordered_map> m_pendingLockStrings; }; diff --git a/vendor/github.com/carbonengine/vcpkg-registry b/vendor/github.com/carbonengine/vcpkg-registry index de86dca..a578f47 160000 --- a/vendor/github.com/carbonengine/vcpkg-registry +++ b/vendor/github.com/carbonengine/vcpkg-registry @@ -1 +1 @@ -Subproject commit de86dcad60458ef170911adb5c42a053fc5d9117 +Subproject commit a578f475b76a204b85f777692adc26bde7cdf01c diff --git a/vendor/github.com/microsoft/vcpkg b/vendor/github.com/microsoft/vcpkg index b2c7468..44819aa 160000 --- a/vendor/github.com/microsoft/vcpkg +++ b/vendor/github.com/microsoft/vcpkg @@ -1 +1 @@ -Subproject commit b2c74683ecfd6a8e7d27ffb0df077f66a9339509 +Subproject commit 44819aa2a6c10e56065e2b0330e7d6c89d1d2574