aspire icon indicating copy to clipboard operation
aspire copied to clipboard

[AzureTools][Aspire] The sequence number of the log changes when returning "Resource" and then clicking "View" of the project or container under the "Logs" in the Dashboard again

Open v-mengwe opened this issue 1 year ago • 6 comments

Update: More is broken here than just the order of logs. See https://github.com/dotnet/aspire/issues/4893#issuecomment-2274700970 for details.


Regression: Not a regression, this issue also reproduces on VS 17.11.0 preview 3 with Aspire 8.0.0

Clean machine: Win11 x64 23h2 ENU VS Version: VS 17.12.0 Preview 1.0 [35113.27.main] Aspire Version: 8.1.0-preview.1.24362.2 Apply NuGet Feeds

REPRO STEPS:

  1. Create a new .NET Aspire Starter Application with redis checked -> Run dotnet run in the AppHost.project folder.
  2. Click "View" of the project or container under the "Logs" in the Dashboard.
  3. Return to "Resource" -> Click "View" of the project or container under the "Logs" in the Dashboard again.
  4. Check whether the sequence number of the log remains unchanged.

Expect: The sequence number of the log remains unchanged.

Actual: The sequence number of the log changes. Actual1 gif

More Info: This issue also reproduces for other projects.

v-mengwe avatar Jul 15 '24 09:07 v-mengwe

@mitchdenny this isn't coming from dashboard, maybe from AppHost? see mention above.

adamint avatar Jul 16 '24 14:07 adamint

I think we discussed tackling this in 8.2.

mitchdenny avatar Jul 21 '24 11:07 mitchdenny

We will need to bump up the priority if logs are out of order or lost. Can someone confirm if that is the case? @karolz-ms / @mitchdenny / @adamint

CC: @joperezr @adityamandaleeka

kvenkatrajan avatar Aug 07 '24 15:08 kvenkatrajan

Based on the screenshot, this might be a duplicate of https://github.com/dotnet/aspire/issues/4942, which was fixed yesterday.

karolz-ms avatar Aug 07 '24 18:08 karolz-ms

The blank lines are unrelated.

JamesNK avatar Aug 08 '24 00:08 JamesNK

The issues with logging are caused by how logging was originally designed: the host is always listening to logs from DCP and stores them in memory. That design was then changed to only listening when someone views the Console logs page in the dashboard.

The change to only listen while the Console logs page is open means that logs are fetched from DCP and "replayed" into memory in the host. That causes issues:

  1. The order of logs is wrong. When logs are replayed, the data is merged from std-out, err-out, etc, into one stream. No thought is given to when they originally arrived when merging them together. Imagine an app that ran for 10 minutes, and during that time it evenly wrote 1000 logs to std-out, and 10 logs to err-out. All the error logs are near the beginning of the log output instead of spaced evenly. Also, it is a race to add logs from different sources into the single stream, so logs from std-out and err-out will change order.

  2. The line number is wrong. Each time logs are replayed then log number increases. Imagine there are 10 logs. Instead of always showing lines 1-10, each refresh of the page increases the number. It goes to 11-20, 21-30, 31-40, etc.

  3. Logs written to ResourceLoggerService are lost. The way this feature was implemented is it assumed it could add a log to host's in-memory collection. However, now that in-memory collection is cleared and refilled when DCP logs when someone views the Console logs page.

JamesNK avatar Aug 08 '24 01:08 JamesNK

Bug in DCP that didn't add timestamps to some logs is resolved. Will look at this next week.

JamesNK avatar Aug 17 '24 07:08 JamesNK

Verify this issue fixed on the latest Aspire 8.1.1-preview.1.24420.9

Rita003 avatar Aug 21 '24 06:08 Rita003