aspire icon indicating copy to clipboard operation
aspire copied to clipboard

Bad experience when viewing console logs for a resource with a lot of logs

Open JamesNK opened this issue 1 year ago • 8 comments
trafficstars

Is there an existing issue for this?

  • [x] I have searched the existing issues

Describe the bug

Visiting the console logs page causes Aspire to load logs. For DCP resources, the host calls DCP get to get its old logs, streaming them from beginning to end, and then continuing to stream new logs as they arrive.

The problem with this the order doesn't match what is shown in the Aspire. Aspire wants to shows the latest logs by default, with a scrollbar to go back and view older logs.

By streaming logs from the beginning, the UI rapidly updates as it quickly tries to render logs from beginning to end, causing the UI to freeze, lock up, and generally behave badly. A resource with 10,000 logs does a lot of UI updates for lines 1-9900 before 9901-10000 are actually displayed.

Expected Behavior

Ideally:

  1. The dashboard quickly displays the latest logs.
  2. The dashboard streams new logs as they arrive.
  3. The dashboard loads historical logs in the background.

A couple of solutions I see:

  1. The current DCP method to get console logs is tweaked:

    1. Add a parameter to limit the amount of historical logs returned. The dashboard never attempts to show more than 10,000 logs in the past so this could be passed to provide an upper limit on the amount of data DCP attempts to return.
    2. The DCP method adds a header with a count of the current number of logs available. This could be used by Aspire to display a loading indicator in logs. The console logs wouldn't start being displayed until the amount of lines received from DCP equals this line count. This change would stop the UI from trying to display older logs as they're returned. The downside is there would be a delay while displaying the loading indicator as old logs are loaded.
  2. Another option would be for there to be two calls to get log data from DCP:

    1. One call to stream the last 100 logs, plus new logs. This call would need to return a total log count in the header so the line number is accurate when logs are initially displayed.
    2. Another call to stream historical logs. It would load old logs in the background.
    3. NOTE: Aspire host doesn't use the order that logs are received for ordering, just the date. Theoritically there could be one API call that simulatanously returns logs from newest to oldest while at the same time returning latest logs.

I think option 1 is probably easy both from hosting and DCP perspective. Option 2 would create a better experience by making logs consistently load quickly.

Steps To Reproduce

No response

Exceptions (if any)

No response

.NET Version info

No response

Anything else?

No response

JamesNK avatar Oct 14 '24 07:10 JamesNK

cc @davidfowl @mitchdenny @karolz-ms @danegsta

JamesNK avatar Oct 14 '24 07:10 JamesNK

We definitely don't want to see the Blazor UX freeze up, nor do we want the backend of the dashboard or the apphost to eat a lot of resources just for logs that the user doesn't want to see. So anything we can do to optimize this is worthwhile.

One thing I thought about is whether we could do this work as part of adding other value to the console logging experience. For example, showing the last x log lines is really a filter function, but I am wondering if we could add text search over the logs as part of this?

The other dimension to this is that I know that @DamianEdwards and @davidfowl want to support a model where the dashboard is a persistent resource.

mitchdenny avatar Oct 14 '24 08:10 mitchdenny

Text search wouldn't be difficult. Logs are in memory after loading, so the work would mostly be in the UI. But this issue is focused on loading the logs.

Dashboard as a persistent resource doesn't matter either way. The dashboard doesn't keep all logs in-memory even when it's running. Navigating away from the console logs page clears them from memory.

JamesNK avatar Oct 14 '24 08:10 JamesNK

We definitely don't want to see the Blazor UX freeze up, nor do we want the backend of the dashboard or the apphost to eat a lot of resources just for logs that the user doesn't want to see. So anything we can do to optimize this is worthwhile.

One thing I thought about is whether we could do this work as part of adding other value to the console logging experience. For example, showing the last x log lines is really a filter function, but I am wondering if we could add text search over the logs as part of this?

The other dimension to this is that I know that @DamianEdwards and @davidfowl want to support a model where the dashboard is a persistent resource.

100% on the text search ... would love to see a filter box similar to what chrome has for javascript console logs ... even better if a regex

aktxyz avatar Jan 05 '25 16:01 aktxyz

@JamesNK sorry for late reply

We are a little bit constrained on DCP side in terms of what new options we can support for log streaming because of differences between Containers and Executables, and between various container engines. The following is the set of new options for log requests that can be implemented while keeping these constraints satisfied:

  1. limit=N this would limit the logs response to N log lines. This option is compatible with tail and since (see below), but not follow.
  2. tail=Nlimits the logs response to (at most) N EXISTING, newest log lines. If follow is set, new log lines that appear after the log stream was created do not count against the limit, and will be streamed until the client closes the stream. Not compatible with since.
  3. since=T limits the logs response to log lines created after timestamp T.

Unfortunately it is not possible for DCP to efficiently determine how many log lines are available for Containers. We could implement that for Executables only if that helps.

I believe the dashboard could implement efficient log retrieval by combining the "latest log" stream (tail=page_size, follow=true) with retrieving "previous pages" of logs on demand (tail=reverse_page_number*page_size, limit=page_size). Let me know please if my understanding is correct and if the since option makes things easier.

@danegsta @dbreshears FYI

karolz-ms avatar Feb 13 '25 01:02 karolz-ms

A fundamental problem we have with console logs today is content is streamed from oldest to newest, but that is the wrong direction for the UI. In the UI we want to immediately display the newest logs.

Ideally what we want is:

  1. Get logs from newest to oldest, and
  2. Get new logs as they arrive

That lets the UI quickly show the latest log content, with older logs loading in over time (1), while at the same time showing new logs as they arrive (2). Perhaps there should be two calls to DCP to get this data.

Next time there is a free hard problems meeting we should discuss this area. I apprieticate there are technical limitations, so a real time discussion about what work best would be good.

JamesNK avatar Feb 13 '25 02:02 JamesNK

@karolz-ms Do you plan to make improvements here for 9.3? If so, what changes will be required in the dashboard side?

JamesNK avatar Apr 29 '25 22:04 JamesNK

@JamesNK yes. The PR to add skip, limit and tail options to DCP is in review right now. Once it is merged and the new version of DCP is integrated with Aspire, I plan to add these API definitions to Aspire DCP client. This should be a small work item.

After this the dashboard/dashboard service can use these new capabilities to improve the logs experience along the lines you outlined in the original description for this issue. I am not sure if you/your team has any room left to do any work on this in 9.3 timeframe?

karolz-ms avatar Apr 30 '25 00:04 karolz-ms

https://github.com/dotnet/aspire/pull/9593 added new log stream options to DCP API definitions in Aspire. This should make it possible for app model and dashboard to improve on the log viewing experience.

karolz-ms avatar May 30 '25 22:05 karolz-ms