🐛 Fix signature issue in activitypub outgoing process

🔊 Add more logging during activitypub process for debug
2025-12-29 22:31:24 +08:00
parent 05a02046a9
commit 84da11f301
4 changed files with 150 additions and 32 deletions
--- a/DysonNetwork.Sphere/ActivityPub/ActivityPubActivityProcessor.cs
+++ b/DysonNetwork.Sphere/ActivityPub/ActivityPubActivityProcessor.cs
@@ -19,17 +19,28 @@ public class ActivityPubActivityProcessor(
        Dictionary<string, object> activity
    )
    {
+        logger.LogInformation("Incoming activity request. Username: {Username}, Path: {Path}", 
+            username, context.Request.Path);
+        
+        var activityType = activity.GetValueOrDefault("type")?.ToString();
+        var activityId = activity.GetValueOrDefault("id")?.ToString();
+        var actor = activity.GetValueOrDefault("actor")?.ToString();
+        
+        logger.LogInformation("Activity details - Type: {Type}, ID: {Id}, Actor: {Actor}", 
+            activityType, activityId, actor);
+        
        if (!signatureService.VerifyIncomingRequest(context, out var actorUri))
        {
-            logger.LogWarning("Failed to verify signature for incoming activity");
+            logger.LogWarning("Failed to verify signature for incoming activity. Type: {Type}, From: {Actor}", 
+                activityType, actor);
            return false;
        }
        
        if (string.IsNullOrEmpty(actorUri))
            return false;
        
-        var activityType = activity.GetValueOrDefault("type")?.ToString();
-        logger.LogInformation("Processing activity type: {Type} from actor: {Actor}", activityType, actorUri);
+        logger.LogInformation("Signature verified successfully. Processing {Type} from {ActorUri}", 
+            activityType, actorUri);
        
        switch (activityType)
        {
@@ -52,7 +63,8 @@ public class ActivityPubActivityProcessor(
            case "Update":
                return await ProcessUpdateAsync(actorUri, activity);
            default:
-                logger.LogWarning("Unsupported activity type: {Type}", activityType);
+                logger.LogWarning("Unsupported activity type: {Type}. Full activity: {Activity}", 
+                    activityType, JsonSerializer.Serialize(activity));
                return false;
        }
    }
@@ -60,19 +72,32 @@ public class ActivityPubActivityProcessor(
    private async Task<bool> ProcessFollowAsync(string actorUri, Dictionary<string, object> activity)
    {
        var objectUri = activity.GetValueOrDefault("object")?.ToString();
+        var activityId = activity.GetValueOrDefault("id")?.ToString();
+        
+        logger.LogInformation("Processing Follow. Actor: {ActorUri}, Target: {ObjectUri}, ActivityId: {Id}", 
+            actorUri, objectUri, activityId);
+        
        if (string.IsNullOrEmpty(objectUri))
+        {
+            logger.LogWarning("Follow activity missing object field");
            return false;
+        }
        
        var actor = await GetOrCreateActorAsync(actorUri);
+        var targetUsername = ExtractUsernameFromUri(objectUri);
        var targetPublisher = await db.Publishers
-            .FirstOrDefaultAsync(p => p.Name == ExtractUsernameFromUri(objectUri));
+            .FirstOrDefaultAsync(p => p.Name == targetUsername);
        
        if (targetPublisher == null)
        {
-            logger.LogWarning("Target publisher not found: {Uri}", objectUri);
+            logger.LogWarning("Target publisher not found: {Uri}, ExtractedUsername: {Username}", 
+                objectUri, targetUsername);
            return false;
        }
        
+        logger.LogInformation("Target publisher found: {PublisherName} (ID: {Id})", 
+            targetPublisher.Name, targetPublisher.Id);
+        
        var existingRelationship = await db.FediverseRelationships
            .FirstOrDefaultAsync(r => 
                r.ActorId == actor.Id && 
@@ -81,7 +106,8 @@ public class ActivityPubActivityProcessor(
        
        if (existingRelationship != null && existingRelationship.State == RelationshipState.Accepted)
        {
-            logger.LogInformation("Follow relationship already exists");
+            logger.LogInformation("Follow relationship already exists and is accepted. ActorId: {ActorId}, PublisherId: {PublisherId}", 
+                actor.Id, targetPublisher.Id);
            return true;
        }
        
@@ -98,6 +124,13 @@ public class ActivityPubActivityProcessor(
                IsFollowedBy = true
            };
            db.FediverseRelationships.Add(existingRelationship);
+            logger.LogInformation("Created new follow relationship. ActorId: {ActorId}, TargetActorId: {TargetActorId}", 
+                actor.Id, actor.Id);
+        }
+        else
+        {
+            logger.LogInformation("Updating existing relationship. CurrentState: {State}, NewState: Pending", 
+                existingRelationship.State);
        }
        
        await db.SaveChangesAsync();
@@ -105,10 +138,11 @@ public class ActivityPubActivityProcessor(
        await deliveryService.SendAcceptActivityAsync(
            targetPublisher.Id,
            actorUri,
-            activity.GetValueOrDefault("id")?.ToString() ?? ""
+            activityId ?? ""
        );
        
-        logger.LogInformation("Processed follow from {Actor} to {Target}", actorUri, objectUri);
+        logger.LogInformation("Processed follow from {Actor} to {Target}. RelationshipState: Pending", 
+            actorUri, objectUri);
        return true;
    }

--- a/DysonNetwork.Sphere/ActivityPub/ActivityPubController.cs
+++ b/DysonNetwork.Sphere/ActivityPub/ActivityPubController.cs
@@ -43,11 +43,11 @@ public class ActivityPubController(
        var outboxUrl = $"{actorUrl}/outbox";
        var followersUrl = $"{actorUrl}/followers";
        var followingUrl = $"{actorUrl}/following";
-        var assetsBaseUrl = configuration["ActivityPub:FileBaseUrl"] ?? $"https://{Domain}/files";
+        var assetsBaseUrl = configuration["AssetsServerBaseUrl"] ?? $"https://{Domain}/files";

        var actor = new ActivityPubActor
        {
-            Context = ["https://www.w3.org/ns/activitystreams"],
+            Context = ["https://www.w3.org/ns/activitystreams", "https://w3id.org/security/v1"],
            Id = actorUrl,
            Type = "Person",
            Name = publisher.Nick,
@@ -75,15 +75,12 @@ public class ActivityPubController(
                    Url = $"{assetsBaseUrl}/{publisher.Background.Id}"
                }
                : null,
-            PublicKeys =
-            [
-                new ActivityPubPublicKey
-                {
-                    Id = $"{actorUrl}#main-key",
-                    Owner = actorUrl,
-                    PublicKeyPem = GetPublicKey(publisher)
-                }
-            ]
+            PublicKey = new ActivityPubPublicKey
+            {
+                Id = $"{actorUrl}#main-key",
+                Owner = actorUrl,
+                PublicKeyPem = GetPublicKey(publisher)
+            }
        };

        return Ok(actor);
@@ -345,7 +342,7 @@ public class ActivityPubActor
    [JsonPropertyName("url")] public string? Url { get; set; }
    [JsonPropertyName("icon")] public ActivityPubImage? Icon { get; set; }
    [JsonPropertyName("image")] public ActivityPubImage? Image { get; set; }
-    [JsonPropertyName("publicKey")] public List<ActivityPubPublicKey>? PublicKeys { get; set; }
+    [JsonPropertyName("publicKey")] public ActivityPubPublicKey? PublicKey { get; set; }
 }

 public class ActivityPubPublicKey
--- a/DysonNetwork.Sphere/ActivityPub/ActivityPubDeliveryService.cs
+++ b/DysonNetwork.Sphere/ActivityPub/ActivityPubDeliveryService.cs
@@ -241,6 +241,12 @@ public class ActivityPubDeliveryService(
            var hash = sha256.ComputeHash(bodyBytes);
            var digest = $"SHA-256={Convert.ToBase64String(hash)}";
            request.Headers.Add("Digest", digest);
+            request.Headers.Add("Host", new Uri(inboxUrl).Host);
+            
+            logger.LogInformation("Preparing request to {Inbox}", inboxUrl);
+            logger.LogInformation("Request body (truncated): {Body}", json.Substring(0, Math.Min(200, json.Length)) + "...");
+            logger.LogInformation("Request headers before signing: Date={Date}, Digest={Digest}, Host={Host}", 
+                request.Headers.Date, digest, request.Headers.Host);
            
            var signatureHeaders = await signatureService.SignOutgoingRequest(request, actorUri);
            var signature = signatureHeaders;
@@ -251,15 +257,30 @@ public class ActivityPubDeliveryService(
                               $"signature=\"{signature["signature"]}\"";
            
            request.Headers.Add("Signature", signatureString);
-            request.Headers.Add("Host", new Uri(inboxUrl).Host);
+            
+            logger.LogInformation("Full signature header: {Signature}", signatureString);
+            logger.LogInformation("Request headers after signing:");
+            foreach (var header in request.Headers)
+            {
+                var value = header.Value.Any() ? header.Value.First() : string.Empty;
+                if (header.Key == "signature")
+                {
+                    value = value.Substring(0, Math.Min(100, value.Length)) + "...";
+                }
+                logger.LogInformation("  {Key}: {Value}", header.Key, value);
+            }
            
            var response = await HttpClient.SendAsync(request);
            var responseContent = await response.Content.ReadAsStringAsync();
            
+            logger.LogInformation("Response from {Inbox}. Status: {Status}", inboxUrl, response.StatusCode);
+            
            if (!response.IsSuccessStatusCode)
            {
-                logger.LogWarning("Failed to send activity to {Inbox}. Status: {Status}, Response: {Response}",
+                logger.LogError("Failed to send activity to {Inbox}. Status: {Status}, Response: {Response}",
                    inboxUrl, response.StatusCode, responseContent);
+                logger.LogError("Full request details: Method={Method}, Uri={Uri}, ContentType={ContentType}",
+                    request.Method, request.RequestUri, request.Content?.Headers.ContentType);
                return false;
            }
            
@@ -268,7 +289,7 @@ public class ActivityPubDeliveryService(
        }
        catch (Exception ex)
        {
-            logger.LogError(ex, "Error sending activity to {Inbox}", inboxUrl);
+            logger.LogError(ex, "Error sending activity to {Inbox}. Exception: {Message}", inboxUrl, ex.Message);
            return false;
        }
    }
--- a/DysonNetwork.Sphere/ActivityPub/ActivityPubSignatureService.cs
+++ b/DysonNetwork.Sphere/ActivityPub/ActivityPubSignatureService.cs
@@ -22,24 +22,33 @@ public class ActivityPubSignatureService(
        actorUri = null;
        
        if (!context.Request.Headers.ContainsKey("Signature"))
+        {
+            logger.LogWarning("Request missing Signature header. Path: {Path}", context.Request.Path);
            return false;
+        }
        
        var signatureHeader = context.Request.Headers["Signature"].ToString();
+        logger.LogInformation("Incoming request with signature. Path: {Path}, SignatureHeader: {Signature}", 
+            context.Request.Path, signatureHeader);
+        
        var signatureParts = ParseSignatureHeader(signatureHeader);
        
        if (signatureParts == null)
        {
-            logger.LogWarning("Invalid signature header format");
+            logger.LogWarning("Invalid signature header format. SignatureHeader: {Signature}", signatureHeader);
            return false;
        }
        
        actorUri = signatureParts.GetValueOrDefault("keyId");
        if (string.IsNullOrEmpty(actorUri))
        {
-            logger.LogWarning("No keyId in signature");
+            logger.LogWarning("No keyId in signature. SignatureParts: {Parts}", 
+                string.Join(", ", signatureParts.Select(kvp => $"{kvp.Key}={kvp.Value}")));
            return false;
        }
        
+        logger.LogInformation("Verifying signature for actor: {ActorUri}", actorUri);
+        
        var actor = GetActorByKeyId(actorUri);
        if (actor == null)
        {
@@ -49,13 +58,16 @@ public class ActivityPubSignatureService(
        
        if (string.IsNullOrEmpty(actor.PublicKey))
        {
-            logger.LogWarning("Actor has no public key: {ActorId}", actor.Id);
+            logger.LogWarning("Actor has no public key. ActorId: {ActorId}, Uri: {Uri}", actor.Id, actor.Uri);
            return false;
        }
        
        var signingString = BuildSigningString(context, signatureParts);
        var signature = signatureParts.GetValueOrDefault("signature");
        
+        logger.LogInformation("Built signing string for verification. SigningString: {SigningString}, Signature: {Signature}", 
+            signingString, signature?.Substring(0, Math.Min(50, signature?.Length ?? 0)) + "...");
+        
        if (string.IsNullOrEmpty(signingString) || string.IsNullOrEmpty(signature))
        {
            logger.LogWarning("Failed to build signing string or extract signature");
@@ -65,7 +77,14 @@ public class ActivityPubSignatureService(
        var isValid = keyService.Verify(actor.PublicKey, signingString, signature);
        
        if (!isValid)
-            logger.LogWarning("Signature verification failed for actor: {ActorUri}", actorUri);
+        {
+            logger.LogError("Signature verification failed for actor: {ActorUri}. SigningString: {SigningString}", 
+                actorUri, signingString);
+        }
+        else
+        {
+            logger.LogInformation("Signature verified successfully for actor: {ActorUri}", actorUri);
+        }
        
        return isValid;
    }
@@ -82,10 +101,18 @@ public class ActivityPubSignatureService(
        var keyPair = GetOrGenerateKeyPair(publisher);
        var keyId = $"{actorUri}#main-key";
        
-        var headersToSign = new[] { "(request-target)", "host", "date", "digest" };
+        logger.LogInformation("Signing outgoing request. ActorUri: {ActorUri}, PublisherId: {PublisherId}", 
+            actorUri, publisher.Id);
+        
+        var headersToSign = new[] { "(request-target)", "host", "date", "digest", "content-type" };
        var signingString = BuildSigningStringForRequest(request, headersToSign);
+        
+        logger.LogInformation("Signing string for outgoing request: {SigningString}", signingString);
+        
        var signature = keyService.Sign(keyPair.privateKeyPem, signingString);
        
+        logger.LogInformation("Generated signature: {Signature}", signature.Substring(0, Math.Min(50, signature.Length)) + "...");
+        
        return new Dictionary<string, string>
        {
            ["keyId"] = keyId,
@@ -197,6 +224,10 @@ public class ActivityPubSignatureService(
    private string BuildSigningStringForRequest(HttpRequestMessage request, string[] headers)
    {
        var sb = new StringBuilder();
+        logger.LogInformation("Building signing string for request. Headers to sign: {Headers}", 
+            string.Join(", ", headers));
+        logger.LogInformation("Request details: Method={Method}, Uri={Uri}", 
+            request.Method, request.RequestUri);
        
        foreach (var header in headers)
        {
@@ -211,23 +242,58 @@ public class ActivityPubSignatureService(
                var method = request.Method.Method.ToLower();
                var path = request.RequestUri?.PathAndQuery ?? "/";
                sb.Append($"{method} {path}");
+                logger.LogInformation("  (request-target): {Value}", $"{method} {path}");
            }
            else if (header == "host")
            {
-                sb.Append(request.RequestUri?.Host);
+                if (request.Headers.Contains("Host"))
+                {
+                    var value = request.Headers.GetValues("Host").First();
+                    sb.Append(value);
+                    logger.LogInformation("  host: {Value}", value);
+                }
+                else
+                {
+                    logger.LogWarning("Host header not found in request");
+                }
            }
            else if (header == "date")
            {
                if (request.Headers.Contains("Date"))
                {
-                    sb.Append(request.Headers.GetValues("Date").First());
+                    var value = request.Headers.GetValues("Date").First();
+                    sb.Append(value);
+                    logger.LogInformation("  date: {Value}", value);
+                }
+                else
+                {
+                    logger.LogWarning("Date header not found in request");
                }
            }
            else if (header == "digest")
            {
                if (request.Headers.Contains("Digest"))
                {
-                    sb.Append(request.Headers.GetValues("Digest").First());
+                    var value = request.Headers.GetValues("Digest").First();
+                    sb.Append(value);
+                    logger.LogInformation("  digest: {Value}", value);
+                }
+                else
+                {
+                    logger.LogWarning("Digest header not found in request");
+                }
+            }
+            else if (header == "content-type")
+            {
+                if (request.Content?.Headers.Contains("Content-Type") == true)
+                {
+                    var value = request.Content.Headers.GetValues("Content-Type").First();
+                    sb.Append(value);
+                    logger.LogInformation("  content-type: {Value}", value);
+                }
+                else
+                {
+                    logger.LogWarning("Content-Type header not found in request");
                }
            }
        }