Skip to content

Commit

Permalink
Add a per-SteamClient unique identifier message to DebugLog messages …
Browse files Browse the repository at this point in the history 
…(2) (#777)

* Wrap logging operations with CMClient to identify the source of log messages
* Allow consumers to override cmclient id
  • Loading branch information
@yaakov-h
yaakov-h authored Nov 4, 2019
1 parent 7a1b475 commit 58562fc
Show file tree
Hide file tree
Showing 14 changed files with 238 additions and 96 deletions.
22 changes: 12 additions & 10 deletions SteamKit2/SteamKit2/Networking/Steam3/EnvelopeEncryptedConnection.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -7,10 +7,11 @@ namespace SteamKit2
{
class EnvelopeEncryptedConnection : IConnection
{
public EnvelopeEncryptedConnection( IConnection inner, EUniverse universe )
public EnvelopeEncryptedConnection( IConnection inner, EUniverse universe, ILogContext log )
{
this.inner = inner ?? throw new ArgumentNullException( nameof(inner) );
this.universe = universe;
this.log = log ?? throw new ArgumentNullException( nameof( log ) );

inner.NetMsgReceived += OnNetMsgReceived;
inner.Connected += OnConnected;
Expand All @@ -19,6 +20,7 @@ public EnvelopeEncryptedConnection( IConnection inner, EUniverse universe )

readonly IConnection inner;
readonly EUniverse universe;
readonly ILogContext log;
EncryptionState state;
INetFilterEncryption? encryption;

Expand Down Expand Up @@ -74,17 +76,17 @@ void OnNetMsgReceived( object sender, NetMsgEventArgs e )
return;
}

var packetMsg = CMClient.GetPacketMsg( e.Data );
var packetMsg = CMClient.GetPacketMsg( e.Data, log );

if ( packetMsg == null )
{
DebugLog.WriteLine( nameof(EnvelopeEncryptedConnection), "Failed to parse message during channel setup, shutting down connection" );
log.LogDebug( nameof(EnvelopeEncryptedConnection), "Failed to parse message during channel setup, shutting down connection" );
Disconnect( userInitiated: false );
return;
}
else if ( !IsExpectedEMsg( packetMsg.MsgType ) )
{
DebugLog.WriteLine( nameof(EnvelopeEncryptedConnection), "Rejected EMsg: {0} during channel setup", packetMsg.MsgType );
log.LogDebug( nameof(EnvelopeEncryptedConnection), "Rejected EMsg: {0} during channel setup", packetMsg.MsgType );
return;
}

Expand All @@ -107,7 +109,7 @@ void HandleEncryptRequest( IPacketMsg packetMsg )
var connectedUniverse = request.Body.Universe;
var protoVersion = request.Body.ProtocolVersion;

DebugLog.WriteLine( nameof(EnvelopeEncryptedConnection), "Got encryption request. Universe: {0} Protocol ver: {1}", connectedUniverse, protoVersion );
log.LogDebug( nameof(EnvelopeEncryptedConnection), "Got encryption request. Universe: {0} Protocol ver: {1}", connectedUniverse, protoVersion );
DebugLog.Assert( protoVersion == 1, nameof(EnvelopeEncryptedConnection), "Encryption handshake protocol version mismatch!" );
DebugLog.Assert( connectedUniverse == universe, nameof(EnvelopeEncryptedConnection), FormattableString.Invariant( $"Expected universe {universe} but server reported universe {connectedUniverse}" ) );

Expand All @@ -125,7 +127,7 @@ void HandleEncryptRequest( IPacketMsg packetMsg )

if ( publicKey == null )
{
DebugLog.WriteLine(nameof(EnvelopeEncryptedConnection), "HandleEncryptRequest got request for invalid universe! Universe: {0} Protocol ver: {1}", connectedUniverse, protoVersion );
log.LogDebug( nameof(EnvelopeEncryptedConnection), "HandleEncryptRequest got request for invalid universe! Universe: {0} Protocol ver: {1}", connectedUniverse, protoVersion );

Disconnect( userInitiated: false );
return;
Expand Down Expand Up @@ -160,11 +162,11 @@ void HandleEncryptRequest( IPacketMsg packetMsg )

if (randomChallenge != null)
{
encryption = new NetFilterEncryptionWithHMAC( tempSessionKey );
encryption = new NetFilterEncryptionWithHMAC( tempSessionKey, log );
}
else
{
encryption = new NetFilterEncryption( tempSessionKey );
encryption = new NetFilterEncryption( tempSessionKey, log );
}

state = EncryptionState.Challenged;
Expand All @@ -175,7 +177,7 @@ void HandleEncryptResult( IPacketMsg packetMsg )
{
var result = new Msg<MsgChannelEncryptResult>( packetMsg );

DebugLog.WriteLine( nameof(EnvelopeEncryptedConnection), "Encryption result: {0}", result.Body.Result );
log.LogDebug( nameof(EnvelopeEncryptedConnection), "Encryption result: {0}", result.Body.Result );
Debug.Assert( encryption != null );

if ( result.Body.Result == EResult.OK && encryption != null )
Expand All @@ -185,7 +187,7 @@ void HandleEncryptResult( IPacketMsg packetMsg )
}
else
{
DebugLog.WriteLine( nameof(EnvelopeEncryptedConnection), "Encryption channel setup failed" );
log.LogDebug( nameof(EnvelopeEncryptedConnection), "Encryption channel setup failed" );
Disconnect( userInitiated: false );
}
}
Expand Down
7 changes: 5 additions & 2 deletions SteamKit2/SteamKit2/Networking/Steam3/NetFilterEncryption.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@
*/


using System;
using System.IO;
using System.Security.Cryptography;

Expand All @@ -12,12 +13,14 @@ namespace SteamKit2
class NetFilterEncryption : INetFilterEncryption
{
readonly byte[] sessionKey;
readonly ILogContext log;

public NetFilterEncryption( byte[] sessionKey )
public NetFilterEncryption( byte[] sessionKey, ILogContext log )
{
DebugLog.Assert( sessionKey.Length == 32, nameof(NetFilterEncryption), "AES session key was not 32 bytes!" );

this.sessionKey = sessionKey;
this.log = log ?? throw new ArgumentNullException( nameof( log ) );
}

public byte[] ProcessIncoming( byte[] data )
Expand All @@ -28,7 +31,7 @@ public byte[] ProcessIncoming( byte[] data )
}
catch ( CryptographicException ex )
{
DebugLog.WriteLine( nameof(NetFilterEncryption), "Unable to decrypt incoming packet: " + ex.Message );
log.LogDebug( nameof(NetFilterEncryption), "Unable to decrypt incoming packet: " + ex.Message );

// rethrow as an IO exception so it's handled in the network thread
throw new IOException( "Unable to decrypt incoming packet", ex );
Expand Down
6 changes: 4 additions & 2 deletions SteamKit2/SteamKit2/Networking/Steam3/NetFilterEncryptionWithHMAC.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -14,12 +14,14 @@ class NetFilterEncryptionWithHMAC : INetFilterEncryption
{
readonly byte[] sessionKey;
readonly byte[] hmacSecret;
readonly ILogContext log;

public NetFilterEncryptionWithHMAC( byte[] sessionKey )
public NetFilterEncryptionWithHMAC( byte[] sessionKey, ILogContext log )
{
DebugLog.Assert( sessionKey.Length == 32, nameof(NetFilterEncryption), "AES session key was not 32 bytes!" );

this.sessionKey = sessionKey;
this.log = log ?? throw new ArgumentNullException( nameof( log ) );
this.hmacSecret = new byte[ 16 ];
Array.Copy( sessionKey, 0, hmacSecret, 0, hmacSecret.Length );
}
Expand All @@ -32,7 +34,7 @@ public byte[] ProcessIncoming( byte[] data )
}
catch ( CryptographicException ex )
{
DebugLog.WriteLine( nameof(NetFilterEncryptionWithHMAC), "Unable to decrypt incoming packet: " + ex.Message );
log.LogDebug( nameof(NetFilterEncryptionWithHMAC), "Unable to decrypt incoming packet: " + ex.Message );

// rethrow as an IO exception so it's handled in the network thread
throw new IOException( "Unable to decrypt incoming packet", ex );
Expand Down
30 changes: 16 additions & 14 deletions SteamKit2/SteamKit2/Networking/Steam3/TcpConnection.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@ class TcpConnection : IConnection
{
const uint MAGIC = 0x31305456; // "VT01"

private ILogContext log;
private Socket? socket;
private Thread? netThread;
private NetworkStream? netStream;
Expand All @@ -25,8 +26,9 @@ class TcpConnection : IConnection
private CancellationTokenSource? cancellationToken;
private object netLock;

public TcpConnection()
public TcpConnection(ILogContext log)
{
this.log = log ?? throw new ArgumentNullException( nameof( log ) );
netLock = new object();
}

Expand Down Expand Up @@ -102,19 +104,19 @@ private void ConnectCompleted(bool success)
// If we have no cancellation token source, we were already Release()'ed
if (cancellationToken?.IsCancellationRequested ?? true)
{
DebugLog.WriteLine("TcpConnection", "Connection request to {0} was cancelled", CurrentEndPoint);
log.LogDebug("TcpConnection", "Connection request to {0} was cancelled", CurrentEndPoint);
if (success) Shutdown();
Release( userRequestedDisconnect: true );
return;
}
else if (!success)
{
DebugLog.WriteLine("TcpConnection", "Timed out while connecting to {0}", CurrentEndPoint);
log.LogDebug( "TcpConnection", "Timed out while connecting to {0}", CurrentEndPoint);
Release( userRequestedDisconnect: false );
return;
}

DebugLog.WriteLine("TcpConnection", "Connected to {0}", CurrentEndPoint);
log.LogDebug( "TcpConnection", "Connected to {0}", CurrentEndPoint);

try
{
Expand All @@ -136,7 +138,7 @@ private void ConnectCompleted(bool success)
}
catch (Exception ex)
{
DebugLog.WriteLine("TcpConnection", "Exception while setting up connection to {0}: {1}", CurrentEndPoint, ex);
log.LogDebug( "TcpConnection", "Exception while setting up connection to {0}: {1}", CurrentEndPoint, ex);
Release( userRequestedDisconnect: false );
}
}
Expand All @@ -148,7 +150,7 @@ private void TryConnect(object sender)
int timeout = (int)sender;
if (cancellationToken.IsCancellationRequested)
{
DebugLog.WriteLine("TcpConnection", "Connection to {0} cancelled by user", CurrentEndPoint);
log.LogDebug( "TcpConnection", "Connection to {0} cancelled by user", CurrentEndPoint);
Release( userRequestedDisconnect: true );
return;
}
Expand All @@ -163,7 +165,7 @@ private void TryConnect(object sender)
}
catch ( Exception ex )
{
DebugLog.WriteLine( "TcpConnection", "Socket exception while completing connection request to {0}: {1}", CurrentEndPoint, ex );
log.LogDebug( "TcpConnection", "Socket exception while completing connection request to {0}: {1}", CurrentEndPoint, ex );
ConnectCompleted( false );
}
}
Expand All @@ -190,7 +192,7 @@ public void Connect(EndPoint endPoint, int timeout)
socket.SendTimeout = timeout;

CurrentEndPoint = endPoint;
DebugLog.WriteLine( "TcpConnection", "Connecting to {0}...", CurrentEndPoint);
log.LogDebug( "TcpConnection", "Connecting to {0}...", CurrentEndPoint);
TryConnect( timeout );
}

Expand Down Expand Up @@ -227,7 +229,7 @@ void NetLoop()
}
catch (SocketException ex)
{
DebugLog.WriteLine("TcpConnection", "Socket exception while polling: {0}", ex);
log.LogDebug( "TcpConnection", "Socket exception while polling: {0}", ex);
break;
}

Expand All @@ -246,7 +248,7 @@ void NetLoop()
}
catch (IOException ex)
{
DebugLog.WriteLine("TcpConnection", "Socket exception occurred while reading packet: {0}", ex);
log.LogDebug("TcpConnection", "Socket exception occurred while reading packet: {0}", ex);
break;
}

Expand All @@ -256,7 +258,7 @@ void NetLoop()
}
catch (Exception ex)
{
DebugLog.WriteLine("TcpConnection", "Unexpected exception propogated back to NetLoop: {0}", ex);
log.LogDebug( "TcpConnection", "Unexpected exception propogated back to NetLoop: {0}", ex);
}
}

Expand Down Expand Up @@ -309,7 +311,7 @@ public void Send( byte[] data )
{
if (socket == null || netStream == null)
{
DebugLog.WriteLine("TcpConnection", "Attempting to send client data when not connected.");
log.LogDebug( "TcpConnection", "Attempting to send client data when not connected.");
return;
}

Expand All @@ -321,7 +323,7 @@ public void Send( byte[] data )
}
catch (IOException ex)
{
DebugLog.WriteLine("TcpConnection", "Socket exception while writing data: {0}", ex);
log.LogDebug( "TcpConnection", "Socket exception while writing data: {0}", ex);
}
}
}
Expand All @@ -341,7 +343,7 @@ public IPAddress GetLocalIP()
}
catch (Exception ex)
{
DebugLog.WriteLine("TcpConnection", "Socket exception trying to read bound IP: {0}", ex);
log.LogDebug( "TcpConnection", "Socket exception trying to read bound IP: {0}", ex);
return IPAddress.None;
}
}
Expand Down
Loading

0 comments on commit 58562fc

Please sign in to comment.