notfire/Iceshrimp.NET
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

[backend] Improved debug logging (ISH-238)

Browse source
This commit is contained in:
Laura Hausmann 2024-04-10 00:15:46 +02:00
parent 45e8d7eb41
commit c5bd380344
No known key found for this signature in database
GPG key ID: D044E84C5BE01605
9 changed files with 45 additions and 23 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

10
Iceshrimp.Backend/Core/Federation/ActivityPub/ActivityFetcherService.cs
View file

@ -41,8 +41,9 @@ public class ActivityFetcherService(
return await FetchRawActivityAsync(url, actor, keypair);
}
public async Task<IEnumerable<ASObject>> FetchActivityAsync(string url, User actor, UserKeypair keypair)
private async Task<IEnumerable<ASObject>> FetchActivityAsync(string url, User actor, UserKeypair keypair)
{
logger.LogDebug("Fetching activity {url} as user {id}", url, actor.Id);
var (activity, finalUri) = await FetchActivityInternal(url, actor, keypair);
if (activity == null) return [];
@ -55,7 +56,8 @@ public class ActivityFetcherService(
if (activityIdUri.Host != finalUri.Host)
throw GracefulException.UnprocessableEntity("Activity identifier doesn't match final host");
logger.LogDebug("Fetching activity {url} as user {id} (attempt 2)", activityIdUri.AbsoluteUri, actor.Id);
(activity, finalUri) = await FetchActivityInternal(activityIdUri.AbsoluteUri, actor, keypair);
if (activity == null) return [];
@ -138,7 +140,7 @@ public class ActivityFetcherService(
}
}
public async Task<string?> FetchRawActivityAsync(string url, User actor, UserKeypair keypair)
private async Task<string?> FetchRawActivityAsync(string url, User actor, UserKeypair keypair)
{
var request = httpRqSvc.GetSigned(url, AcceptableActivityTypes, actor, keypair).DisableAutoRedirects();
var response = await client.SendAsync(request);
@ -197,7 +199,7 @@ public class ActivityFetcherService(
public async Task<ASNote?> FetchNoteAsync(string uri, User actor)
{
var keypair = await db.UserKeypairs.FirstOrDefaultAsync(p => p.User == actor) ??
throw new Exception("User has no keypair");
throw new Exception("Actor has no keypair");
var activity = await FetchActivityAsync(uri, actor, keypair);
return activity.OfType<ASNote>().FirstOrDefault();
}

2
Iceshrimp.Backend/Core/Federation/ActivityPub/ObjectResolver.cs
View file

@ -16,6 +16,8 @@ public class ObjectResolver(
{
public async Task<ASObject?> ResolveObject(ASObjectBase baseObj, int recurse = 5, bool force = false)
{
logger.LogDebug("Resolving object: {id}", baseObj.Id ?? "<anonymous>");
if (baseObj is ASActivity { Object.IsUnresolved: true } activity && recurse > 0)
{
activity.Object = await ResolveObject(activity.Object, --recurse, force);

9
Iceshrimp.Backend/Core/Middleware/ErrorHandlerMiddleware.cs
View file

@ -110,11 +110,12 @@ public class ErrorHandlerMiddleware(
if (!ce.SuppressLog)
{
if (ce.Details != null)
logger.LogDebug("Request {id} was rejected with {statusCode} {error}: {message} - {details}",
ctx.TraceIdentifier, (int)ce.StatusCode, ce.Error, ce.Message, ce.Details);
logger.LogDebug("Request {id} was rejected by {source} with {statusCode} {error}: {message} - {details}",
ctx.TraceIdentifier, ce.Source, (int)ce.StatusCode, ce.Error, ce.Message,
ce.Details);
else
logger.LogDebug("Request {id} was rejected with {statusCode} {error}: {message}",
ctx.TraceIdentifier, (int)ce.StatusCode, ce.Error, ce.Message);
logger.LogDebug("Request {id} was rejected by {source} with {statusCode} {error}: {message}",
ctx.TraceIdentifier, ce.Source, (int)ce.StatusCode, ce.Error, ce.Message);
}
}
else

3
Iceshrimp.Backend/Core/Queues/DeliverQueue.cs
View file

@ -7,8 +7,7 @@ using JR = System.Text.Json.Serialization.JsonRequiredAttribute;
namespace Iceshrimp.Backend.Core.Queues;
public class DeliverQueue()
: PostgresJobQueue<DeliverJobData>("deliver", DeliverQueueProcessorDelegateAsync, 20)
public class DeliverQueue() : PostgresJobQueue<DeliverJobData>("deliver", DeliverQueueProcessorDelegateAsync, 20)
{
private static async Task DeliverQueueProcessorDelegateAsync(
Job job, DeliverJobData jobData, IServiceProvider scope, CancellationToken token

14
Iceshrimp.Backend/Core/Queues/InboxQueue.cs
View file

@ -18,19 +18,15 @@ public class InboxQueue() : PostgresJobQueue<InboxJobData>("inbox", InboxQueuePr
CancellationToken token
)
{
var expanded = LdHelpers.Expand(JToken.Parse(jobData.Body));
if (expanded == null)
throw new Exception("Failed to expand ASObject");
var obj = ASObject.Deserialize(expanded);
if (obj == null)
throw new Exception("Failed to deserialize ASObject");
var logger = scope.GetRequiredService<ILogger<InboxQueue>>();
logger.LogDebug("Processing inbox job {id}", job.Id.ToString().ToLowerInvariant());
var expanded = LdHelpers.Expand(JToken.Parse(jobData.Body)) ?? throw new Exception("Failed to expand ASObject");
var obj = ASObject.Deserialize(expanded) ?? throw new Exception("Failed to deserialize ASObject");
if (obj is not ASActivity activity)
throw new GracefulException("Job data is not an ASActivity", $"Type: {obj.Type}");
logger.LogTrace("Preparation took {ms} ms", job.Duration);
var apHandler = scope.GetRequiredService<ActivityPub.ActivityHandlerService>();
var logger = scope.GetRequiredService<ILogger<InboxQueue>>();
logger.LogTrace("Preparation took {ms} ms", job.Duration);
await apHandler.PerformActivityAsync(activity, jobData.InboxUserId, jobData.AuthenticatedUserId);
}
}

7
Iceshrimp.Backend/Core/Services/InstanceService.cs
View file

@ -7,7 +7,7 @@ using Microsoft.EntityFrameworkCore;
namespace Iceshrimp.Backend.Core.Services;
public class InstanceService(DatabaseContext db, HttpClient httpClient)
public class InstanceService(DatabaseContext db, HttpClient httpClient, ILogger<InstanceService> logger)
{
private static readonly AsyncKeyedLocker<string> KeyedLocker = new(o =>
{
@ -17,6 +17,11 @@ public class InstanceService(DatabaseContext db, HttpClient httpClient)
private async Task<Instance> GetUpdatedInstanceMetadataAsync(string host, string webDomain)
{
if (host == webDomain)
logger.LogDebug("Updating instance metadata for {host}", host);
else
logger.LogDebug("Updating instance metadata for {host} ({domain})", host, webDomain);
host = host.ToLowerInvariant();
var instance = await db.Instances.FirstOrDefaultAsync(p => p.Host == host);
if (instance == null)

13
Iceshrimp.Backend/Core/Services/NoteService.cs
View file

@ -62,6 +62,8 @@ public class NoteService(
bool localOnly = false
)
{
logger.LogDebug("Creating note for local user {id}", user.Id);
if ((text?.Length ?? 0) + (cw?.Length ?? 0) > config.Value.CharacterLimit)
throw GracefulException
.BadRequest($"Text & content warning cannot exceed {config.Value.CharacterLimit} characters in total");
@ -163,6 +165,8 @@ public class NoteService(
await EnqueuePollExpiryTask(poll);
}
logger.LogDebug("Inserting created note {noteId} for local user {userId} into the database", note.Id, user.Id);
await UpdateNoteCountersAsync(note, true);
await db.AddAsync(note);
@ -246,6 +250,8 @@ public class NoteService(
Poll? poll = null
)
{
logger.LogDebug("Processing note update for note {id}", note.Id);
var noteEdit = new NoteEdit
{
Id = IdHelpers.GenerateSlowflakeId(),
@ -384,6 +390,8 @@ public class NoteService(
public async Task DeleteNoteAsync(Note note)
{
logger.LogDebug("Deleting note {id}", note.Id);
db.Update(note.User);
db.Remove(note);
eventSvc.RaiseNoteDeleted(this, note);
@ -669,6 +677,9 @@ public class NoteService(
var emoji = await emojiSvc.ProcessEmojiAsync(note.Tags?.OfType<ASEmoji>().ToList(), actor.Host);
dbNote.Emojis = emoji.Select(p => p.Id).ToList();
logger.LogDebug("Inserting created note {noteId} for remote user {userId} into the database", note.Id,
actor.Id);
await UpdateNoteCountersAsync(dbNote, true);
await db.Notes.AddAsync(dbNote);
await db.SaveChangesAsync();
@ -690,6 +701,8 @@ public class NoteService(
.FirstOrDefaultAsync(p => p.Uri == note.Id);
if (dbNote == null) return await ProcessNoteAsync(note, actor);
logger.LogDebug("Processing note update {id} for note {noteId}", note.Id, dbNote.Id);
if (dbNote.User != actor)
throw GracefulException.UnprocessableEntity("Refusing to update note of user other than actor");

3
Iceshrimp.Backend/Core/Services/PushService.cs
View file

@ -47,6 +47,9 @@ public class PushService(
if (subscriptions.Count == 0)
return;
logger.LogDebug("Delivering mastodon push notification {id} for user {userId}", notification.Id,
notification.Notifiee.Id);
var isSelf = notification.Notifier == notification.Notifiee;
var followed = subscriptions.All(p => p.Policy != PushSubscription.PushPolicy.Followed) ||

7
Iceshrimp.Backend/Core/Services/QueueService.cs
View file

@ -428,15 +428,16 @@ public class PostgresJobQueue<T>(
job.ExceptionMessage = e.Message;
job.ExceptionSource = e.TargetSite?.DeclaringType?.FullName ?? "Unknown";
var logger = scope.ServiceProvider.GetRequiredService<ILogger<QueueService>>();
var logger = scope.ServiceProvider.GetRequiredService<ILogger<QueueService>>();
var queueName = data is BackgroundTaskJobData ? name + $" ({data.GetType().Name})" : name;
if (e is GracefulException { Details: not null } ce)
{
logger.LogError("Failed to process job in {queue} queue: {error} - {details}",
name, ce.Message, ce.Details);
queueName, ce.Message, ce.Details);
}
else
{
logger.LogError(e, "Failed to process job in {queue} queue:", name);
logger.LogError(e, "Failed to process job in {queue} queue:", queueName);
}
}