Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Logging ordering fixes and feedback #5398

Merged
merged 4 commits into from
Aug 27, 2024
Merged

Logging ordering fixes and feedback #5398

merged 4 commits into from
Aug 27, 2024

Conversation

JamesNK
Copy link
Member

@JamesNK JamesNK commented Aug 23, 2024

Description

Following feedback from the previous PR and discussion with Karol about what options we have for getting logs from DCP, it's clear that there isn't a robust, fast, simple way to stream correctly ordered console logs from the host. The only way to produce the correct order is to do a final sort on the client.

This PR:

  • Removes flaky time based delay from the server. It isn't possible to perfectly order log lines before they are returned from the service. Don't attempt to delay sending while ordering.

  • Shares code for how log entries are internally represented on the client (dashboard) and server (host). Parsing and sorting logic is shared to ensure the backlog and client results match in content and order.

  • Improves how sorting is implemented. Log lines with dates are placed in sorted order, while those without dates are placed in the order they were received. This mades ordering somewhat complicated, but there are tests, and I think it's important for the dashboard to be resilient to receiving whatever data it gets given as logs. In saying that, I want to make sure DCP always includes log lines with a prefixed date.

  • Changes ResourceLoggerService to use one lock. I didn't see the benefit of multiple. It makes locking easier to reason with and reduces the chance of accidential deadlock.

  • Resource logger state backlog is cleared immediately when there are no longer any subscribers. Previously they were cleared via a notificated sent through a number of channels. A race condition could cause logs to be watched again before they were cleared. That would cause logs to be double returned: the backlog + all logs from the start again.

Fixes #4893

Checklist

  • Is this feature complete?
    • Yes. Ready to ship.
    • No. Follow-up changes expected.
  • Are you including unit tests for the changes and scenario tests if relevant?
    • Yes
    • No
  • Did you add public API?
    • Yes
      • If yes, did you have an API Review for it?
        • Yes
        • No
      • Did you add <remarks /> and <code /> elements on your triple slash comments?
        • Yes
        • No
    • No
  • Does the change make any security assumptions or guarantees?
    • Yes
      • If yes, have you done a threat model and had a security review?
        • Yes
        • No
    • No
  • Does the change require an update in our Aspire docs?
    • Yes
      • Link to aspire-docs issue:
    • No
Microsoft Reviewers: Open in CodeFlow

@JamesNK JamesNK added area-dashboard area-app-model Issues pertaining to the APIs in Aspire.Hosting, e.g. DistributedApplication labels Aug 23, 2024
@JamesNK JamesNK requested a review from mitchdenny as a code owner August 23, 2024 08:42
@JamesNK JamesNK changed the title WIP Logging ordering fixes and feedback Aug 23, 2024
@JamesNK JamesNK requested a review from davidfowl August 23, 2024 08:45
@JamesNK JamesNK force-pushed the jamesnk/logging-refactor branch from 169743a to e5f9167 Compare August 23, 2024 08:53
DateTime? timestamp = null;
var resolvedContent = content;

if (TimestampParser.TryParseConsoleTimestamp(resolvedContent, out var result))
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why do we parse the timestamp out here, just to turn around and put them back together in the ResourceLoggerService? Why not just leave the timestamp in the content, and pass it all the way up to the dashboard. And only need to parse it out once in the UI?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I did this so the content in the host LogEntry was consistent with the client LogEntry.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why do we need them to be consistent? The host can just deal with the logs as lines of content.

it’s only the UI that wants them to be sorted by date time, so why would we force the host to parse the time out?

Copy link
Member Author

@JamesNK JamesNK Aug 27, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

They don't need to be consistent; I just think it's simpler to reason about everything when it's consistent and it allows more code to be shared between the host and dashboard.

In the host, either the ILogger logs need to add a timestamp to log line content or DCP logs need to remove a timestamp from log line content. Either way, it's slightly weird.

I chose to make the DCP logs remove the time stamp over the alternative for the reasons above. The downside there are some extra allocations as logs are received and sent by the host, the upside is storing the backlog uses less memory. DateTime is smaller than vs 15ish UTF16 chars in the log message.

@JamesNK JamesNK mentioned this pull request Aug 25, 2024
16 tasks
@JamesNK JamesNK force-pushed the jamesnk/logging-refactor branch from 954731f to 29572c9 Compare August 26, 2024 07:16
@JamesNK JamesNK force-pushed the jamesnk/logging-refactor branch from 48a58d8 to 5cf820d Compare August 26, 2024 08:45
@JamesNK JamesNK merged commit 4ee91ed into main Aug 27, 2024
11 checks passed
@JamesNK JamesNK deleted the jamesnk/logging-refactor branch August 27, 2024 05:32
@github-actions github-actions bot locked and limited conversation to collaborators Sep 26, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
area-app-model Issues pertaining to the APIs in Aspire.Hosting, e.g. DistributedApplication area-dashboard
Projects
None yet
4 participants