Repository: featbit/featbit (language: python)

Issue:
[Good First Issues]: Add Connection Information to Featbit Eval Server logs 
# Description
Currently, the logging functions defined in `ConnectionHandler.Log.cs` class only log the `connectionId`, and error message if there was one, and in some cases an event.

`connectionId` is not very helpful in tracking down which client interaction caused the log message.

The logs should include the ~~project id~~, the environment id, client IP address, and client hostname if availabe.

With this information system admins will be able to find the project, environment, and client associated with a log message

The client IP address can be obtained in 'StreamingMiddleware.cs' by capturing one of the following (see references)

`context.Connection.RemoteIpAddress`
`HttpContext.GetServerVariable("HTTP_X_FORWARDED_FOR");`
`Request.Headers["CF-CONNECTING-IP"];`

The hostname can be retrieved with
`Dns.GetHostEntry(<ip address variable>).HostName;`

These should be passed to `RequestHandler` and added to the `Connection` Object, Connections should not fail or throw exceptions if the client IP, or hostname are not retrieveable, they should instead be empty strings.

~~The projectId can be obtained using the MongoDbClient with a query similar to the following~~

~~The projectId retrieval ideally will be feature gated using an environment variable such as `EVAL_LOG_PROJECT_ID` with a default of false. this is to avoid adding potential latency to the initial websocket connection while this feature matures.~~


`LoggerMessage` Attriubutes and associated Funcitons in `ConnectionHandler.Log.cs` should be updated to include `envId`, ~~`projectId`~~, `clientId`, and `clientHostname`

Refactor function callers to include this information.

#References

https://juldhais.net/how-to-get-client-ip-address-and-location-information-in-asp-net-core-c2bb50e689c3


# Scope

Evaluation Server

# Screenshot

# Setup dev environment

Please read the [doc](../blob/main/Development.md) to set up your development environment.

# Deadline

We usually give 2 weeks for a feature request, which means you have 2 weeks to implement the feature starting from the
day it is assigned to you. If you have any difficulties, please contact us in [Slack](https://join.slack.com/t/featbit/shared_invite/zt-1ew5e2vbb-x6Apan1xZOaYMnFzqZkGNQ).

# How to implement

1. Fork the FeatBit repository.
2. Create a branch issues-{issues number}
3. Implement the task based on Description and Scope mentioned above.
4. Submit your PR

If the feature is UI related, make sure you complete the following tasks before submit your PR:

- merge featbit main branch into your working branch
- run `npm run i18n`
- commit **messages.xlf & messages.zh.xlf** file changes (if any)

# Contribution points

Each contribution counts a certain number of points, depending on its difficulty. Contributors earn the appropriate
points when the work is merged. Contribution points are used to describe the contributions that contributors have made.
They can also be used to receive rewards for community events. You can view the current community submissions on a
public [google sheet](https://docs.google.com/spreadsheets/d/1ukyXgi_jRPeXj7EAST0IrnPfLOQ6xDBkcyAJY9N-Yb4/edit#gid=1117970540).

Points: 4

# How to claim to solve the issue

If you want to implement this function, please leave a comment in this issue like:

> I'd like to implement this function, please assign this issue to me.



Discussion / hints:
I can implement this functionality, please assign this issue to me.
Regarding the retrieval of the projectId, I'm working on another PR related to this. In that PR, I'll store the environment secret in Redis, with the key being `featbit:secret:{the-secret-string}`, and the value being a list of hash entries.

The code looks like this:

```csharp
public async Task UpsertSecretAsync(Guid envId, Secret secret)
{
    var key = RedisKeys.Secret(secret.Value);
    var fields = new HashEntry[]
    {
        new("envId", envId.ToString()),
        new("envKey", "the-env-key"),
        new("projectId", "the-projectId"),
        new("projectKey", "the-project-key"),
        new("type", secret.Type)
    };

    await _redis.HashSetAsync(key, fields);
}
```

Then, on the evaluation server side, I can retrieve all this secret information from Redis for request validation.

- If the secret is not found in Redis, the request will be rejected.
- If the connection type does not match the secret type, the request will be rejected. (Which means for server-side SDK, we must use server secret, for client-side SDK, we must use client secret)

Since I have all this information, I'll store it in the `Connection` class. Then we can use `connection.Secret.ProjectId` to get the project ID. also, maybe it would be better to use `envKey` and `projectKey` in the logs as it is easier to read.

What do you think of this? @wss-rbrennan 
+1 to using the keys over the IDs.  It'd be easier to follow when triaging issues using the logs.
I removed the projectId requirements from this issue so we don't duplicate the work that @deleteLater is doing to retrieve project information. It can can bee added as a different issue when the data is available in redis.

Fix patch:
diff --git a/modules/evaluation-server/src/Streaming/Connections/Connection.cs b/modules/evaluation-server/src/Streaming/Connections/Connection.cs
index c89e9431f..212b867d9 100644
--- a/modules/evaluation-server/src/Streaming/Connections/Connection.cs
+++ b/modules/evaluation-server/src/Streaming/Connections/Connection.cs
@@ -19,6 +19,10 @@ public class Connection
     /// </summary>
     public EndUser? User { get; set; }
 
+    public string ClientIpAddress { get; }
+    
+    public string ClientHost { get; }
+    
     public string Type { get; }
 
     public string Version { get; }
@@ -33,7 +37,9 @@ public Connection(
         string type,
         string version,
         long? connectAt = null,
-        long? closeAt = null)
+        long? closeAt = null,
+        string clientIpAddress = "",
+        string clientHost = "")
     {
         Id = Guid.NewGuid().ToString("D");
 
@@ -43,6 +49,8 @@ public Connection(
         Version = version;
         ConnectAt = connectAt ?? DateTimeOffset.UtcNow.ToUnixTimeMilliseconds();
         CloseAt = closeAt ?? 0;
+        ClientIpAddress = clientIpAddress;
+        ClientHost = clientHost;
     }
 
     public async Task SendAsync(Message message, CancellationToken cancellationToken)
diff --git a/modules/evaluation-server/src/Streaming/Connections/ConnectionHandler.Log.cs b/modules/evaluation-server/src/Streaming/Connections/ConnectionHandler.Log.cs
index a1f7c8a51..d76fe2955 100644
--- a/modules/evaluation-server/src/Streaming/Connections/ConnectionHandler.Log.cs
+++ b/modules/evaluation-server/src/Streaming/Connections/ConnectionHandler.Log.cs
@@ -6,25 +6,25 @@ public partial class ConnectionHandler
 {
     public static partial class Log
     {
-        [LoggerMessage(1, LogLevel.Error, "{ConnectionId}: exception occurred when process message. {Error}", EventName = "ErrorProcessMessage")]
-        public static partial void ErrorProcessMessage(ILogger logger, string connectionId, string error);
+        [LoggerMessage(1, LogLevel.Error, "{ConnectionId}: exception occurred when process message. {Error} [EnvId: {EnvId}, ClientIP: {ClientIP}, ClientHost: {ClientHost}]", EventName = "ErrorProcessMessage")]
+        public static partial void ErrorProcessMessage(ILogger logger, string connectionId, string error, Guid envId, string clientIp, string clientHost);
         
-        [LoggerMessage(2, LogLevel.Trace, "{ConnectionId}: receive empty message", EventName = "ReceiveEmptyMessage")]
-        public static partial void ReceiveEmptyMessage(ILogger logger, string connectionId);
+        [LoggerMessage(2, LogLevel.Trace, "{ConnectionId}: receive empty message [EnvId: {EnvId}, ClientIP: {ClientIP}, ClientHost: {ClientHost}]", EventName = "ReceiveEmptyMessage")]
+        public static partial void ReceiveEmptyMessage(ILogger logger, string connectionId, Guid envId, string clientIp, string clientHost);
 
-        [LoggerMessage(3, LogLevel.Trace, "{ConnectionId}: receive close message", EventName = "ReceiveCloseMessage")]
-        public static partial void ReceiveCloseMessage(ILogger logger, string connectionId);
+        [LoggerMessage(3, LogLevel.Trace, "{ConnectionId}: receive close message [EnvId: {EnvId}, ClientIP: {ClientIP}, ClientHost: {ClientHost}]", EventName = "ReceiveCloseMessage")]
+        public static partial void ReceiveCloseMessage(ILogger logger, string connectionId, Guid envId, string clientIp, string clientHost);
         
-        [LoggerMessage(4, LogLevel.Warning, "{ConnectionId}: error occurred while read message. {Error}", EventName = "ErrorReadMessage")]
-        public static partial void ErrorReadMessage(ILogger logger, string connectionId, string error);
+        [LoggerMessage(4, LogLevel.Warning, "{ConnectionId}: error occurred while read message. {Error} [EnvId: {EnvId}, ClientIP: {ClientIP}, ClientHost: {ClientHost}]", EventName = "ErrorReadMessage")]
+        public static partial void ErrorReadMessage(ILogger logger, string connectionId, string error, Guid envId, string clientIp, string clientHost);
         
-        [LoggerMessage(5, LogLevel.Warning, "{ConnectionId}: receive invalid message.", EventName = "ReceiveInvalidMessage")]
-        public static partial void ReceiveInvalidMessage(ILogger logger, string connectionId, Exception exception);
+        [LoggerMessage(5, LogLevel.Warning, "{ConnectionId}: receive invalid message. [EnvId: {EnvId}, ClientIP: {ClientIP}, ClientHost: {ClientHost}]", EventName = "ReceiveInvalidMessage")]
+        public static partial void ReceiveInvalidMessage(ILogger logger, string connectionId, Guid envId, string clientIp, string clientHost, Exception exception);
 
-        [LoggerMessage(6, LogLevel.Error, "{ConnectionId}: failed handle message.", EventName = "ErrorHandleMessage")]
-        public static partial void ErrorHandleMessage(ILogger logger, string connectionId, Exception exception);
+        [LoggerMessage(6, LogLevel.Error, "{ConnectionId}: failed handle message. [EnvId: {EnvId}, ClientIP: {ClientIP}, ClientHost: {ClientHost}]", EventName = "ErrorHandleMessage")]
+        public static partial void ErrorHandleMessage(ILogger logger, string connectionId, Guid envId, string clientIp, string clientHost, Exception exception);
 
-        [LoggerMessage(7, LogLevel.Warning, "{ConnectionId}: cannot find message handler for type {MessageType}", EventName = "CannotFindMessageHandler")]
-        public static partial void CannotFindMessageHandler(ILogger logger, string connectionId, string messageType);
+        [LoggerMessage(7, LogLevel.Warning, "{ConnectionId}: cannot find message handler for type {MessageType} [EnvId: {EnvId}, ClientIP: {ClientIP}, ClientHost: {ClientHost}]", EventName = "CannotFindMessageHandler")]
+        public static partial void CannotFindMessageHandler(ILogger logger, string connectionId, string messageType, Guid envId, string clientIp, string clientHost);
     }
 }
\ No newline at end of file
diff --git a/modules/evaluation-server/src/Streaming/Connections/ConnectionHandler.cs b/modules/evaluation-server/src/Streaming/Connections/ConnectionHandler.cs
index 2ccd0f65a..ac06716fe 100644
--- a/modules/evaluation-server/src/Streaming/Connections/ConnectionHandler.cs
+++ b/modules/evaluation-server/src/Streaming/Connections/ConnectionHandler.cs
@@ -55,7 +55,7 @@ public async Task OnConnectedAsync(Connection connection, CancellationToken canc
             }
             catch (Exception ex)
             {
-                Log.ErrorProcessMessage(_logger, connection.Id, ex.Message);
+                Log.ErrorProcessMessage(_logger, connection.Id, ex.Message, connection.EnvId, connection.ClientIpAddress, connection.ClientHost);
             }
         }
 
@@ -74,13 +74,13 @@ public async Task OnMessageAsync(Connection connection, Message message, Cancell
     {
         if (message.Type == WebSocketMessageType.Close)
         {
-            Log.ReceiveCloseMessage(_logger, connection.Id);
+            Log.ReceiveCloseMessage(_logger, connection.Id, connection.EnvId, connection.ClientIpAddress, connection.ClientHost);
             return;
         }
 
         if (message.Bytes.IsEmpty)
         {
-            Log.ReceiveEmptyMessage(_logger, connection.Id);
+            Log.ReceiveEmptyMessage(_logger, connection.Id, connection.EnvId, connection.ClientIpAddress, connection.ClientHost);
             return;
         }
 
@@ -93,7 +93,7 @@ public async Task OnMessageAsync(Connection connection, Message message, Cancell
 
     public void OnMessageError(Connection connection, string error)
     {
-        Log.ErrorReadMessage(_logger, connection.Id, error);
+        Log.ErrorReadMessage(_logger, connection.Id, error, connection.EnvId, connection.ClientIpAddress, connection.ClientHost);
     }
 
     public async Task HandleMessageAsync(Connection connection, Message message, CancellationToken token)
@@ -116,7 +116,7 @@ public async Task HandleMessageAsync(Connection connection, Message message, Can
             var handler = _messageHandlers.FirstOrDefault(x => x.Type == messageType);
             if (handler == null)
             {
-                Log.CannotFindMessageHandler(_logger, connection.Id, messageType ?? "");
+                Log.CannotFindMessageHandler(_logger, connection.Id, messageType ?? "", connection.EnvId, connection.ClientIpAddress, connection.ClientHost);
                 return;
             }
 
@@ -126,12 +126,12 @@ public async Task HandleMessageAsync(Connection connection, Message message, Can
         catch (JsonException ex)
         {
             // ignore invalid json
-            Log.ReceiveInvalidMessage(_logger, connection.Id, ex);
+            Log.ReceiveInvalidMessage(_logger, connection.Id, connection.EnvId, connection.ClientIpAddress, connection.ClientHost, ex);
         }
         catch (Exception ex)
         {
             // error when handle message
-            Log.ErrorHandleMessage(_logger, connection.Id, ex);
+            Log.ErrorHandleMessage(_logger, connection.Id, connection.EnvId, connection.ClientIpAddress, connection.ClientHost, ex);
         }
     }
 }
\ No newline at end of file
diff --git a/modules/evaluation-server/src/Streaming/Shared/RequestHandler.cs b/modules/evaluation-server/src/Streaming/Shared/RequestHandler.cs
index 4dd57707c..5538ae267 100644
--- a/modules/evaluation-server/src/Streaming/Shared/RequestHandler.cs
+++ b/modules/evaluation-server/src/Streaming/Shared/RequestHandler.cs
@@ -11,7 +11,9 @@ public class RequestHandler
         string version,
         string tokenString,
         // for testability
-        long? currentTimestamp = null)
+        long? currentTimestamp = null,
+        string clientIpAddress = "",
+        string clientHost = "")
     {
         // connection type
         if (!ConnectionType.IsRegistered(sdkType))
@@ -45,7 +47,7 @@ public class RequestHandler
             return null;
         }
 
-        var connection = new Connection(webSocket, token.Secret.EnvId, sdkType, version, current);
+        var connection = new Connection(webSocket, token.Secret.EnvId, sdkType, version, current, null, clientIpAddress, clientHost);
         return connection;
     }
 }
\ No newline at end of file
diff --git a/modules/evaluation-server/src/Streaming/StreamingMiddleware.cs b/modules/evaluation-server/src/Streaming/StreamingMiddleware.cs
index 208b23a09..70dca4796 100644
--- a/modules/evaluation-server/src/Streaming/StreamingMiddleware.cs
+++ b/modules/evaluation-server/src/Streaming/StreamingMiddleware.cs
@@ -1,4 +1,5 @@
-﻿using System.Net.WebSockets;
+﻿using System.Net;
+using System.Net.WebSockets;
 using Microsoft.AspNetCore.Http;
 using Microsoft.Extensions.Hosting;
 using Microsoft.Extensions.Internal;
@@ -42,9 +43,11 @@ public async Task InvokeAsync(HttpContext context, IConnectionHandler handler)
         // try accept request
         var query = request.Query;
         var currentTimestamp = _systemClock.UtcNow.ToUnixTimeMilliseconds();
+        var clientIpAddress = GetClientIpAddress(context);
+        var clientHost = await GetClientHostAsync(clientIpAddress);
 
         var connection =
-            RequestHandler.TryAcceptRequest(ws, query["type"], query["version"], query["token"], currentTimestamp);
+            RequestHandler.TryAcceptRequest(ws, query["type"], query["version"], query["token"], currentTimestamp, clientIpAddress, clientHost);
         if (connection == null)
         {
             await ws.CloseOutputAsync(
@@ -58,4 +61,40 @@ await ws.CloseOutputAsync(
         // use ApplicationStopping token
         await handler.OnConnectedAsync(connection, _applicationLifetime.ApplicationStopping);
     }
+
+    private string GetClientIpAddress(HttpContext context)
+    {
+        if (context.Request.Headers.TryGetValue("X-Forwarded-For", out var forwardForHeaders))
+        {
+            return forwardForHeaders.FirstOrDefault(string.Empty);
+        }
+        // cloudflare connecting IP header
+        // https://developers.cloudflare.com/fundamentals/reference/http-request-headers/#cf-connecting-ip
+        if (context.Request.Headers.TryGetValue("CF-Connecting-IP", out var cfConnectingIpHeaders))
+        {
+            return cfConnectingIpHeaders.FirstOrDefault(string.Empty);
+        }
+        
+        var remoteIpAddr = context.Connection.RemoteIpAddress?.ToString();
+        return remoteIpAddr ?? string.Empty;
+    }
+
+    private async Task<string> GetClientHostAsync(string clientIpAddress)
+    {
+        if (string.IsNullOrEmpty(clientIpAddress))
+        {
+            return string.Empty;
+        }
+        
+        try
+        {
+            var cancellationToken = new CancellationTokenSource(TimeSpan.FromSeconds(2)).Token;
+            return (await Dns.GetHostEntryAsync(clientIpAddress, cancellationToken)).HostName;
+        }
+        catch (Exception)
+        {
+            // allow clientHost to stay empty without failing the connection.
+            return string.Empty;
+        }
+    }
 }
\ No newline at end of file


Test patch:
diff --git a/modules/evaluation-server/tests/Streaming.UnitTests/Connections/ConnectionBuilder.cs b/modules/evaluation-server/tests/Streaming.UnitTests/Connections/ConnectionBuilder.cs
new file mode 100644
index 000000000..6b415e02f
--- /dev/null
+++ b/modules/evaluation-server/tests/Streaming.UnitTests/Connections/ConnectionBuilder.cs
@@ -0,0 +1,76 @@
+using System.Net.WebSockets;
+using Moq;
+using Streaming.Connections;
+
+namespace Streaming.UnitTests.Connections;
+
+public class ConnectionBuilder
+{
+    private Mock<WebSocket> _wsMock = new();
+    private string _ip = "10.0.0.7";
+    private string _host = "test.client.host";
+    private string _connectionType = ConnectionType.Server;
+    private Guid _envId = TestData.DevEnvId;
+    private long _connectAt = DateTime.UtcNow.Ticks;
+    private string _version = "1.0";
+
+    public ConnectionBuilder WithClientIp(string ip)
+    {
+        _ip = ip;
+        return this;
+    }
+
+    public ConnectionBuilder WithClientHost(string host)
+    {
+        _host = host;
+        return this;
+    }
+
+    public ConnectionBuilder WithEnvId(Guid envId)
+    {
+        _envId = envId;
+        return this;
+    }
+
+    public ConnectionBuilder WithMockWebSocket(Mock<WebSocket> ws)
+    {
+        _wsMock = ws;
+        return this;
+    }
+
+    public ConnectionBuilder WithConnectionType(string connectionType)
+    {
+        if (!ConnectionType.IsRegistered(connectionType))
+        {
+            throw new Exception("Invalid ConnectionType.");
+        }
+
+        _connectionType = connectionType;
+        return this;
+    }
+
+    public ConnectionBuilder WithConnectAt(long connectAt)
+    {
+        this._connectAt = connectAt;
+        return this;
+    }
+    
+    public ConnectionBuilder WithVersion(string version)
+    {
+        _version = version;
+        return this;
+    }
+
+    public Connection Build()
+    {
+        return new Connection(
+            _wsMock.Object, 
+            _envId, 
+            _connectionType, 
+            _version,
+            _connectAt,
+            null, 
+            _ip, 
+            _host);
+    }
+}
\ No newline at end of file
diff --git a/modules/evaluation-server/tests/Streaming.UnitTests/Connections/ConnectionHandlerTests.cs b/modules/evaluation-server/tests/Streaming.UnitTests/Connections/ConnectionHandlerTests.cs
new file mode 100644
index 000000000..e26160ca8
--- /dev/null
+++ b/modules/evaluation-server/tests/Streaming.UnitTests/Connections/ConnectionHandlerTests.cs
@@ -0,0 +1,109 @@
+using System.Net.WebSockets;
+using System.Text;
+using Moq;
+using Streaming.Connections;
+using Streaming.Messages;
+using TestBase;
+
+namespace Streaming.UnitTests.Connections;
+
+public class ConnectionHandlerTests
+{
+    [Fact]
+    public void OnMessageErrorLogTests()
+    {
+        var (handler, logger) = Arrange();
+        var connection = new ConnectionBuilder()
+            .WithClientIp("10.0.0.7")
+            .WithClientHost("my.client.host")
+            .WithEnvId(TestData.DevEnvId)
+            .Build();
+        
+        handler.OnMessageError(connection, "error");
+            
+        Assert.NotNull(logger.Message);
+        Assert.Contains("10.0.0.7", logger.Message);
+        Assert.Contains("my.client.host", logger.Message);
+        Assert.Contains(TestData.DevEnvId.ToString(), logger.Message);
+    }
+
+    [Theory]
+    [ClassData(typeof(Messages))]
+    public async Task OnMessageAsyncLogTests(Message message, bool threwException)
+    {
+        var (handler, logger) = Arrange(new ErrorThrowingMessageHandler());
+        var connection = new ConnectionBuilder()
+            .WithClientIp("10.0.0.7")
+            .WithClientHost("my.client.host")
+            .WithEnvId(TestData.DevEnvId)
+            .Build();
+        
+        await handler.OnMessageAsync(connection, message,default);
+
+        Assert.NotNull(logger.Message);
+        if (threwException)
+        {
+            Assert.NotNull(logger.Ex);
+        }
+        else
+        {
+            Assert.Null(logger.Ex);
+        }
+        Assert.Contains("10.0.0.7", logger.Message);
+        Assert.Contains("my.client.host", logger.Message);
+        Assert.Contains(TestData.DevEnvId.ToString(), logger.Message);
+    }
+
+    private (ConnectionHandler handler, InMemoryFakeLogger<ConnectionHandler> logger) Arrange(params IMessageHandler[] handlers)
+    {
+        var logger = new InMemoryFakeLogger<ConnectionHandler>();
+        var mockManager = new Mock<IConnectionManager>();
+        var handler = new ConnectionHandler(mockManager.Object, handlers, logger);
+        return (handler, logger);
+    }
+}
+
+
+public class Messages : TheoryData<Message, bool>
+{
+    public Messages()
+    {
+        // close message log scenario
+        var closeMessage = new Message(new byte[16], WebSocketMessageType.Close);
+        Add(closeMessage, false);
+
+        // empty message log scenario
+        Add(Message.EmptyText, false);
+
+        // missing handler message log scenario
+        var missingHandlerMessage = new Message(
+            Encoding.UTF8.GetBytes("{\"messageType\":\"unregistered\",\"data\":{}}"), 
+            WebSocketMessageType.Text
+        );
+        Add(missingHandlerMessage, false);
+        
+        // invalid json message log scenario
+        var invalidJsonMessage = new Message(
+            Encoding.UTF8.GetBytes("{this is not ][valid json}"),
+            WebSocketMessageType.Text 
+        );
+        Add(invalidJsonMessage, true);
+        
+        // error-throwing message log scenario
+        var errorThrowingMessage = new Message(
+            Encoding.UTF8.GetBytes("{\"messageType\":\"error-throwing\",\"data\":{}}"), 
+            WebSocketMessageType.Text
+        );
+        Add(errorThrowingMessage, true);
+    }
+}
+
+public class ErrorThrowingMessageHandler : IMessageHandler
+{
+    public string Type => "error-throwing";
+
+    public Task HandleAsync(MessageContext ctx)
+    {
+        throw new Exception("Test Error!");
+    }
+}
\ No newline at end of file