Skip to content

Commit 8b0c4dc

Browse files
committed
Track reason for sending stats.
"Stats" really means anything in the protobuf blob. There are many different reasons why we might need to send a message: urgent ping needed to confirm connectivity when we appear to be timing out, keepalive for idle connection, when we actually have some stats we want to send to the peer, or acks. Relayed connections have even more reasons. We were doing a good job of displaying *what* we were sending, but looking at traces it was not always clear to me *why* we weer sending. And you cannot infer the why from the what, because once we decide that we are going to send something, we then opportunistically fit in as much as we can.
1 parent 6c8f74e commit 8b0c4dc

7 files changed

+87
-36
lines changed

src/steamnetworkingsockets/clientlib/steamnetworkingsockets_connections.cpp

Lines changed: 8 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -1971,8 +1971,8 @@ void CSteamNetworkConnectionBase::CheckConnectionStateAndSetNextThinkTime( Steam
19711971
else
19721972
SpewMsg( "[%s] %d reply timeouts, last recv %.1fms ago. Sending keepalive.\n", GetDescription(), m_statsEndToEnd.m_nReplyTimeoutsSinceLastRecv, ( usecNow - m_statsEndToEnd.m_usecTimeLastRecv ) * 1e-3 );
19731973
Assert( m_statsEndToEnd.BNeedToSendPingImmediate( usecNow ) ); // Make sure logic matches
1974-
SendEndToEndPing( true, usecNow );
1975-
AssertMsg( !m_statsEndToEnd.BNeedToSendPingImmediate( usecNow ), "SendEndToEndPing didn't do its job!" );
1974+
SendEndToEndStatsMsg( k_EStatsReplyRequest_Immediate, usecNow, "E2ETimingOutKeepalive" );
1975+
AssertMsg( !m_statsEndToEnd.BNeedToSendPingImmediate( usecNow ), "SendEndToEndStatsMsg didn't do its job!" );
19761976
Assert( m_statsEndToEnd.m_usecInFlightReplyTimeout != 0 );
19771977
}
19781978
else
@@ -2000,8 +2000,8 @@ void CSteamNetworkConnectionBase::CheckConnectionStateAndSetNextThinkTime( Steam
20002000
if ( BCanSendEndToEndData() )
20012001
{
20022002
Assert( m_statsEndToEnd.BNeedToSendKeepalive( usecNow ) ); // Make sure logic matches
2003-
SendEndToEndPing( false, usecNow );
2004-
AssertMsg( !m_statsEndToEnd.BNeedToSendKeepalive( usecNow ), "SendEndToEndPing didn't do its job!" );
2003+
SendEndToEndStatsMsg( k_EStatsReplyRequest_DelayedOK, usecNow, "E2EKeepalive" );
2004+
AssertMsg( !m_statsEndToEnd.BNeedToSendKeepalive( usecNow ), "SendEndToEndStatsMsg didn't do its job!" );
20052005
}
20062006
else
20072007
{
@@ -2212,8 +2212,11 @@ void CSteamNetworkConnectionPipe::FakeSendStats( SteamNetworkingMicroseconds use
22122212
m_statsEndToEnd.TrackSentPacket( cbPktSize );
22132213
}
22142214

2215-
void CSteamNetworkConnectionPipe::SendEndToEndPing( bool bUrgent, SteamNetworkingMicroseconds usecNow )
2215+
void CSteamNetworkConnectionPipe::SendEndToEndStatsMsg( EStatsReplyRequest eRequest, SteamNetworkingMicroseconds usecNow, const char *pszReason )
22162216
{
2217+
NOTE_UNUSED( eRequest );
2218+
NOTE_UNUSED( pszReason );
2219+
22172220
if ( !m_pPartner )
22182221
{
22192222
Assert( false );

src/steamnetworkingsockets/clientlib/steamnetworkingsockets_connections.h

Lines changed: 12 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -76,15 +76,16 @@ struct RemoteConnectionKey_t
7676
/// Base class for connection-type-specific context structure
7777
struct SendPacketContext_t
7878
{
79-
inline SendPacketContext_t( SteamNetworkingMicroseconds usecNow ) : m_usecNow( usecNow ) {}
79+
inline SendPacketContext_t( SteamNetworkingMicroseconds usecNow, const char *pszReason ) : m_usecNow( usecNow ), m_pszReason( pszReason ) {}
8080
const SteamNetworkingMicroseconds m_usecNow;
8181
int m_cbMaxEncryptedPayload;
82+
const char *m_pszReason; // Why are we sending this packet?
8283
};
8384

8485
template<typename TStatsMsg>
8586
struct SendPacketContext : SendPacketContext_t
8687
{
87-
inline SendPacketContext( SteamNetworkingMicroseconds usecNow ) : SendPacketContext_t( usecNow ) {}
88+
inline SendPacketContext( SteamNetworkingMicroseconds usecNow, const char *pszReason ) : SendPacketContext_t( usecNow, pszReason ) {}
8889

8990
uint32 m_nFlags; // Message flags that we need to set.
9091
TStatsMsg msg; // Type-specific stats message
@@ -537,7 +538,7 @@ class CSteamNetworkConnectionBase : protected IThinker
537538
virtual bool BCanSendEndToEndConnectRequest() const = 0;
538539
virtual bool BCanSendEndToEndData() const = 0;
539540
virtual void SendEndToEndConnectRequest( SteamNetworkingMicroseconds usecNow ) = 0;
540-
virtual void SendEndToEndPing( bool bUrgent, SteamNetworkingMicroseconds usecNow ) = 0;
541+
virtual void SendEndToEndStatsMsg( EStatsReplyRequest eRequest, SteamNetworkingMicroseconds usecNow, const char *pszReason ) = 0;
541542
//virtual bool BSendEndToEndPing( SteamNetworkingMicroseconds usecNow );
542543
virtual bool BAllowLocalUnsignedCert() const;
543544

@@ -546,10 +547,14 @@ class CSteamNetworkConnectionBase : protected IThinker
546547
m_receiverState.QueueFlushAllAcks( bImmediate ? 0 : usecNow + k_usecMaxDataAckDelay );
547548
}
548549

549-
bool BNeedToSendEndToEndStatsOrAcks( SteamNetworkingMicroseconds usecNow )
550+
/// Check if we need to send stats or acks. If so, return a reason string
551+
// FIXME - This needs to be refactored. There is some redundancy in the different
552+
// transport code that uses it
553+
const char *NeedToSendEndToEndStatsOrAcks( SteamNetworkingMicroseconds usecNow )
550554
{
551-
return m_receiverState.TimeWhenFlushAcks() <= usecNow ||
552-
m_statsEndToEnd.BNeedToSendStats( usecNow );
555+
if ( m_receiverState.TimeWhenFlushAcks() <= usecNow )
556+
return "SNPFlushAcks";
557+
return m_statsEndToEnd.NeedToSend( usecNow );
553558
}
554559

555560

@@ -698,7 +703,7 @@ class CSteamNetworkConnectionPipe : public CSteamNetworkConnectionBase
698703
virtual bool BCanSendEndToEndConnectRequest() const OVERRIDE;
699704
virtual bool BCanSendEndToEndData() const OVERRIDE;
700705
virtual void SendEndToEndConnectRequest( SteamNetworkingMicroseconds usecNow ) OVERRIDE;
701-
virtual void SendEndToEndPing( bool bUrgent, SteamNetworkingMicroseconds usecNow ) OVERRIDE;
706+
virtual void SendEndToEndStatsMsg( EStatsReplyRequest eRequest, SteamNetworkingMicroseconds usecNow, const char *pszReason ) OVERRIDE;
702707
virtual EResult APIAcceptConnection() OVERRIDE;
703708
virtual bool SendDataPacket( SteamNetworkingMicroseconds usecNow ) OVERRIDE;
704709
virtual int SendEncryptedDataChunk( const void *pChunk, int cbChunk, SendPacketContext_t &ctx ) OVERRIDE;

src/steamnetworkingsockets/clientlib/steamnetworkingsockets_udp.cpp

Lines changed: 19 additions & 19 deletions
Original file line numberDiff line numberDiff line change
@@ -560,7 +560,7 @@ inline uint32 StatsMsgImpliedFlags<CMsgSteamSockets_UDP_Stats>( const CMsgSteamS
560560

561561
struct UDPSendPacketContext_t : SendPacketContext<CMsgSteamSockets_UDP_Stats>
562562
{
563-
inline explicit UDPSendPacketContext_t( SteamNetworkingMicroseconds usecNow ) : SendPacketContext<CMsgSteamSockets_UDP_Stats>( usecNow ) {}
563+
inline explicit UDPSendPacketContext_t( SteamNetworkingMicroseconds usecNow, const char *pszReason ) : SendPacketContext<CMsgSteamSockets_UDP_Stats>( usecNow, pszReason ) {}
564564
int m_nStatsNeed;
565565
};
566566

@@ -607,9 +607,9 @@ void CSteamNetworkConnectionUDP::PopulateSendPacketContext( UDPSendPacketContext
607607
}
608608
}
609609

610-
void CSteamNetworkConnectionUDP::SendStatsMsg( EStatsReplyRequest eReplyRequested, SteamNetworkingMicroseconds usecNow )
610+
void CSteamNetworkConnectionUDP::SendStatsMsg( EStatsReplyRequest eReplyRequested, SteamNetworkingMicroseconds usecNow, const char *pszReason )
611611
{
612-
UDPSendPacketContext_t ctx( usecNow );
612+
UDPSendPacketContext_t ctx( usecNow, pszReason );
613613
PopulateSendPacketContext( ctx, eReplyRequested );
614614

615615
// Send a data packet (maybe containing ordinary data), with this piggy backed on top of it
@@ -619,8 +619,8 @@ void CSteamNetworkConnectionUDP::SendStatsMsg( EStatsReplyRequest eReplyRequeste
619619
bool CSteamNetworkConnectionUDP::SendDataPacket( SteamNetworkingMicroseconds usecNow )
620620
{
621621
// Populate context struct with any stats we want/need to send, and how much space we need to reserve for it
622-
UDPSendPacketContext_t ctx( usecNow );
623-
PopulateSendPacketContext( ctx, k_EStatsReplyRequest_None );
622+
UDPSendPacketContext_t ctx( usecNow, "data" );
623+
PopulateSendPacketContext( ctx, k_EStatsReplyRequest_NothingToSend );
624624

625625
// Send a packet
626626
return SNP_SendPacket( ctx );
@@ -798,29 +798,30 @@ void CSteamNetworkConnectionUDP::SendEndToEndConnectRequest( SteamNetworkingMicr
798798
m_statsEndToEnd.TrackSentPingRequest( usecNow, false );
799799
}
800800

801-
void CSteamNetworkConnectionUDP::SendEndToEndPing( bool bUrgent, SteamNetworkingMicroseconds usecNow )
801+
void CSteamNetworkConnectionUDP::SendEndToEndStatsMsg( EStatsReplyRequest eRequest, SteamNetworkingMicroseconds usecNow, const char *pszReason )
802802
{
803-
SendStatsMsg( bUrgent ? k_EStatsReplyRequest_Immediate : k_EStatsReplyRequest_DelayedOK, usecNow );
803+
SendStatsMsg( eRequest, usecNow, pszReason );
804804
}
805805

806806
void CSteamNetworkConnectionUDP::ThinkConnection( SteamNetworkingMicroseconds usecNow )
807807
{
808808

809+
// FIXME - We should refactor this, maybe promote this to the base class.
810+
// There's really nothing specific to plain UDP transport here.
811+
809812
// Check if we have stats we need to flush out
810813
if ( BStateIsConnectedForWirePurposes() )
811814
{
812815

813816
// Do we need to send something immediately, for any reason?
814-
if (
815-
BNeedToSendEndToEndStatsOrAcks( usecNow )
816-
|| m_statsEndToEnd.BNeedToSendPingImmediate( usecNow )
817-
) {
818-
SendStatsMsg( k_EStatsReplyRequest_None, usecNow );
817+
const char *pszReason = NeedToSendEndToEndStatsOrAcks( usecNow );
818+
if ( pszReason )
819+
{
820+
SendStatsMsg( k_EStatsReplyRequest_NothingToSend, usecNow, pszReason );
819821

820822
// Make sure that took care of what we needed!
821823

822-
Assert( !BNeedToSendEndToEndStatsOrAcks( usecNow ) );
823-
Assert( !m_statsEndToEnd.BNeedToSendPingImmediate( usecNow ) );
824+
Assert( !NeedToSendEndToEndStatsOrAcks( usecNow ) );
824825
}
825826
}
826827
}
@@ -1084,12 +1085,11 @@ void CSteamNetworkConnectionUDP::RecvStats( const CMsgSteamSockets_UDP_Stats &ms
10841085
}
10851086

10861087
// Do we need to send an immediate reply?
1087-
if (
1088-
m_statsEndToEnd.BNeedToSendPingImmediate( usecNow )
1089-
|| BNeedToSendEndToEndStatsOrAcks( usecNow )
1090-
) {
1088+
const char *pszReason = NeedToSendEndToEndStatsOrAcks( usecNow );
1089+
if ( pszReason )
1090+
{
10911091
// Send a stats message
1092-
SendStatsMsg( k_EStatsReplyRequest_None, usecNow );
1092+
SendStatsMsg( k_EStatsReplyRequest_NothingToSend, usecNow, pszReason );
10931093
}
10941094
}
10951095
}

src/steamnetworkingsockets/clientlib/steamnetworkingsockets_udp.h

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -77,7 +77,7 @@ class CSteamNetworkConnectionUDP : public CSteamNetworkConnectionBase
7777
virtual bool BCanSendEndToEndConnectRequest() const OVERRIDE;
7878
virtual bool BCanSendEndToEndData() const OVERRIDE;
7979
virtual void SendEndToEndConnectRequest( SteamNetworkingMicroseconds usecNow ) OVERRIDE;
80-
virtual void SendEndToEndPing( bool bUrgent, SteamNetworkingMicroseconds usecNow ) OVERRIDE;
80+
virtual void SendEndToEndStatsMsg( EStatsReplyRequest eRequest, SteamNetworkingMicroseconds usecNow, const char *pszReason ) OVERRIDE;
8181
virtual void ThinkConnection( SteamNetworkingMicroseconds usecNow ) OVERRIDE;
8282
virtual void GetConnectionTypeDescription( ConnectionTypeDescription_t &szDescription ) const OVERRIDE;
8383
virtual ERemoteUnsignedCert AllowRemoteUnsignedCert() OVERRIDE;
@@ -125,7 +125,7 @@ class CSteamNetworkConnectionUDP : public CSteamNetworkConnectionBase
125125

126126
/// Process stats message, either inline or standalone
127127
void RecvStats( const CMsgSteamSockets_UDP_Stats &msgStatsIn, bool bInline, SteamNetworkingMicroseconds usecNow );
128-
void SendStatsMsg( EStatsReplyRequest eReplyRequested, SteamNetworkingMicroseconds usecNow );
128+
void SendStatsMsg( EStatsReplyRequest eReplyRequested, SteamNetworkingMicroseconds usecNow, const char *pszReason );
129129
void TrackSentStats( const CMsgSteamSockets_UDP_Stats &msgStatsOut, bool bInline, SteamNetworkingMicroseconds usecNow );
130130

131131
void PopulateSendPacketContext( UDPSendPacketContext_t &ctx, EStatsReplyRequest eReplyRequested );

src/steamnetworkingsockets/steamnetworking_statsutils.h

Lines changed: 29 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -584,6 +584,11 @@ struct LinkStatsTrackerBase
584584
/// longer expect the peer to ack, or request to flush stats, etc. (Although we
585585
/// might indicate that we need to send an ack.)
586586
bool m_bDisconnected;
587+
588+
/// Check if we really need to flush out stats now. Derived class should provide the reason strings.
589+
/// (See the code.)
590+
const char *NeedToSendStats( SteamNetworkingMicroseconds usecNow, const char *const arpszReasonStrings[4] );
591+
587592
private:
588593

589594
bool BCheckHaveDataToSendInstantaneous( SteamNetworkingMicroseconds usecNow );
@@ -647,6 +652,30 @@ struct LinkStatsTrackerEndToEnd : public LinkStatsTrackerBase
647652
/// Called when we get a speed sample
648653
void UpdateSpeeds( int nTXSpeed, int nRXSpeed );
649654

655+
/// Do we need to send anything? Return the reason code, or NULL if
656+
/// we don't need to send anything right now
657+
inline const char *NeedToSend( SteamNetworkingMicroseconds usecNow )
658+
{
659+
660+
// Connectivity check because we appear to be timing out?
661+
if ( BNeedToSendPingImmediate( usecNow ) )
662+
return "E2EUrgentPing";
663+
664+
// Ordinary keepalive?
665+
if ( BNeedToSendKeepalive( usecNow ) )
666+
return "E2EKeepalive";
667+
668+
// Stats?
669+
static const char *arpszReasons[4] =
670+
{
671+
nullptr,
672+
"E2EInstantaneousStats",
673+
"E2ELifetimeStats",
674+
"E2EAllStats"
675+
};
676+
return LinkStatsTrackerBase::NeedToSendStats( usecNow, arpszReasons );
677+
}
678+
650679
protected:
651680
void InitInternal( SteamNetworkingMicroseconds usecNow );
652681
void ThinkInternal( SteamNetworkingMicroseconds usecNow );

src/steamnetworkingsockets/steamnetworkingsockets_internal.h

Lines changed: 4 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -187,9 +187,10 @@ const int k_nMinSteamDatagramUDPMsgLen = 5;
187187
/// When sending a stats message, what sort of reply is requested by the calling code?
188188
enum EStatsReplyRequest
189189
{
190-
k_EStatsReplyRequest_None,
191-
k_EStatsReplyRequest_DelayedOK,
192-
k_EStatsReplyRequest_Immediate,
190+
k_EStatsReplyRequest_NothingToSend, // We don't have anything to send at all
191+
k_EStatsReplyRequest_NoReply, // We have something to send, but it does not require a reply
192+
k_EStatsReplyRequest_DelayedOK, // We have something to send, but a delayed reply is OK
193+
k_EStatsReplyRequest_Immediate, // Immediate reply is requested
193194
};
194195

195196
/// Max time that we we should "Nagle" an ack, hoping to combine them together or

src/steamnetworkingsockets/steamnetworkingsockets_shared.cpp

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -618,6 +618,19 @@ bool LinkStatsTrackerBase::BNeedToSendStats( SteamNetworkingMicroseconds usecNow
618618
return bNeedToSendInstantaneous || bNeedToSendLifetime;
619619
}
620620

621+
const char *LinkStatsTrackerBase::NeedToSendStats( SteamNetworkingMicroseconds usecNow, const char *const arpszReasonStrings[4] )
622+
{
623+
// Message already in flight?
624+
if ( m_pktNumInFlight != 0 || m_bDisconnected )
625+
return nullptr;
626+
int n = 0;
627+
if ( m_usecPeerAckedInstaneous + k_usecLinkStatsInstantaneousReportMaxInterval < usecNow && BCheckHaveDataToSendInstantaneous( usecNow ) )
628+
n |= 1;
629+
if ( m_usecPeerAckedLifetime + k_usecLinkStatsLifetimeReportMaxInterval < usecNow && BCheckHaveDataToSendLifetime( usecNow ) )
630+
n |= 2;
631+
return arpszReasonStrings[n];
632+
}
633+
621634
void LinkStatsTrackerBase::PopulateMessage( CMsgSteamDatagramConnectionQuality &msg, SteamNetworkingMicroseconds usecNow )
622635
{
623636
if ( m_pktNumInFlight == 0 && !m_bDisconnected )

0 commit comments

Comments
 (0)