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

Question About JsonSerializer.DeserializeAsyncEnumerable Behavior #56055

Closed
tpeczek opened this issue Jul 20, 2021 · 6 comments · Fixed by #56080
Closed

Question About JsonSerializer.DeserializeAsyncEnumerable Behavior #56055

tpeczek opened this issue Jul 20, 2021 · 6 comments · Fixed by #56080
Assignees
Milestone

Comments

@tpeczek
Copy link

tpeczek commented Jul 20, 2021

Hi,

I have a question around JsonSerializer.DeserializeAsyncEnumerable. I was experimenting with async streaming between ASP.NET Core and HttpClient in .NET 6. I have created two methods on the client side. One which outputs the raw data returned by the ASP.NET Core endpoint.

private static async Task NegotiateRawJsonStreamAsync()
{
	Console.WriteLine($"-- {nameof(NegotiateRawJsonStreamAsync)} --");
	Console.WriteLine($"[{DateTime.UtcNow:hh:mm:ss.fff}] Receving weather forecasts . . .");

	using HttpClient httpClient = new();
	httpClient.DefaultRequestHeaders.Add("Accept", "application/json");

	using HttpResponseMessage response = await httpClient.GetAsync("https://localhost:5001/api/WeatherForecasts/negotiate-stream", HttpCompletionOption.ResponseHeadersRead).ConfigureAwait(false);

	response.EnsureSuccessStatusCode();
	using Stream responseStream = await response.Content.ReadAsStreamAsync().ConfigureAwait(false);

	while (true)
	{
		byte[] buffer = ArrayPool<byte>.Shared.Rent(128);
		int bytesRead = await responseStream.ReadAsync(buffer);

		Console.WriteLine($"[{DateTime.UtcNow:hh:mm:ss.fff}] ({bytesRead}/{buffer.Length}) {Encoding.UTF8.GetString(buffer)}");

                ArrayPool<byte>.Shared.Return(buffer);

		if (bytesRead == 0)
		{
			break;
		}
	}

	Console.WriteLine($"[{DateTime.UtcNow:hh:mm:ss.fff}] Weather forecasts has been received.");
	Console.WriteLine();
}

And one which uses JsonSerializer.DeserializeAsyncEnumerable to deserialize the stream.

private static async Task NegotiateJsonStreamAsync()
{
	Console.WriteLine($"-- {nameof(NegotiateJsonStreamAsync)} --");
	Console.WriteLine($"[{DateTime.UtcNow:hh:mm:ss.fff}] Receving weather forecasts . . .");

	using HttpClient httpClient = new();
	httpClient.DefaultRequestHeaders.Add("Accept", "application/json");

	using HttpResponseMessage response = await httpClient.GetAsync("https://localhost:5001/api/WeatherForecasts/negotiate-stream", HttpCompletionOption.ResponseHeadersRead).ConfigureAwait(false);

	response.EnsureSuccessStatusCode();
	using Stream responseStream = await response.Content.ReadAsStreamAsync().ConfigureAwait(false);

	await foreach (WeatherForecast weatherForecast in JsonSerializer.DeserializeAsyncEnumerable<WeatherForecast>(responseStream, new JsonSerializerOptions { PropertyNameCaseInsensitive = true, DefaultBufferSize = 128 }))
	{
		Console.WriteLine($"[{DateTime.UtcNow:hh:mm:ss.fff}] {weatherForecast.Summary}");
	}

	Console.WriteLine($"[{DateTime.UtcNow:hh:mm:ss.fff}] Weather forecasts has been received.");
	Console.WriteLine();
}

The output from the first one is as follows.

-- NegotiateRawJsonStreamAsync --
[10:35:18.041] Receving weather forecasts . . .
[10:35:18.075] (1/128) [
[10:35:18.184] (89/128) {"dateFormatted":"22.07.2021","temperatureC":49,"temperatureF":120,"summary":"Scorching"}
[10:35:18.286] (89/128) ,{"dateFormatted":"23.07.2021","temperatureC":-20,"temperatureF":-3,"summary":"Freezing"}
[10:35:18.396] (91/128) ,{"dateFormatted":"24.07.2021","temperatureC":49,"temperatureF":120,"summary":"Sweltering"}
[10:35:18.504] (88/128) ,{"dateFormatted":"25.07.2021","temperatureC":-18,"temperatureF":0,"summary":"Freezing"}
[10:35:18.612] (84/128) ,{"dateFormatted":"26.07.2021","temperatureC":30,"temperatureF":85,"summary":"Cool"}
[10:35:18.719] (86/128) ,{"dateFormatted":"27.07.2021","temperatureC":5,"temperatureF":40,"summary":"Bracing"}
[10:35:18.830] (87/128) ,{"dateFormatted":"28.07.2021","temperatureC":-6,"temperatureF":22,"summary":"Bracing"}
[10:35:18.952] (84/128) ,{"dateFormatted":"29.07.2021","temperatureC":13,"temperatureF":55,"summary":"Warm"}
[10:35:19.075] (85/128) ,{"dateFormatted":"30.07.2021","temperatureC":34,"temperatureF":93,"summary":"Balmy"}
[10:35:19.185] (85/128) ,{"dateFormatted":"31.07.2021","temperatureC":36,"temperatureF":96,"summary":"Warm"}]
[10:35:19.204] (0/128)
[10:35:19.212] Weather forecasts has been received.

Which confirms that ASP.NET Core is flushing the results as they come.

The output from the second is as follows.

-- NegotiateJsonStreamAsync --
[10:35:19.218] Receving weather forecasts . . .
[10:35:20.361] Bracing
[10:35:20.362] Mild
[10:35:20.363] Sweltering
[10:35:20.363] Balmy
[10:35:20.363] Bracing
[10:35:20.363] Bracing
[10:35:20.363] Sweltering
[10:35:20.364] Hot
[10:35:20.364] Balmy
[10:35:20.364] Sweltering
[10:35:20.364] Weather forecasts has been received.

This suggest that JsonSerializer.DeserializeAsyncEnumerable is waiting for the entire stream before it starts deserializing.

I haven't found this explained in documentation, so my question would be if this is expected behavior or am I doing something wrong?

The project where I'm plaining with this is available here.

@dotnet-issue-labeler dotnet-issue-labeler bot added area-System.Net.Http untriaged New issue has not been triaged by the area owner labels Jul 20, 2021
@ghost
Copy link

ghost commented Jul 20, 2021

Tagging subscribers to this area: @dotnet/ncl
See info in area-owners.md if you want to be subscribed.

Issue Details

Hi,

I have a question around JsonSerializer.DeserializeAsyncEnumerable. I was experimenting with async streaming between ASP.NET Core and HttpClient in .NET 6. I have created two methods on the client side. One which outputs the raw data returned by the ASP.NET Core endpoint.

private static async Task NegotiateRawJsonStreamAsync()
{
	Console.WriteLine($"-- {nameof(NegotiateRawJsonStreamAsync)} --");
	Console.WriteLine($"[{DateTime.UtcNow:hh:mm:ss.fff}] Receving weather forecasts . . .");

	using HttpClient httpClient = new();
	httpClient.DefaultRequestHeaders.Add("Accept", "application/json");

	using HttpResponseMessage response = await httpClient.GetAsync("https://localhost:5001/api/WeatherForecasts/negotiate-stream", HttpCompletionOption.ResponseHeadersRead).ConfigureAwait(false);

	response.EnsureSuccessStatusCode();

	using Stream contentStream = await response.Content.ReadAsStreamAsync().ConfigureAwait(false);
	while (true)
	{
		byte[] buffer = ArrayPool<byte>.Shared.Rent(16 * 1024); ;
		int bytesRead = await contentStream.ReadAsync(buffer, 0, buffer.Length);

		Console.Out.Write($"[{DateTime.UtcNow:hh:mm:ss.fff}] ({bytesRead}/{buffer.Length}) ");
		Console.Out.Write(Encoding.UTF8.GetString(buffer));
		Console.Out.WriteLine();

		if (bytesRead == 0)
		{
			break;
		}
	}

	Console.WriteLine($"[{DateTime.UtcNow:hh:mm:ss.fff}] Weather forecasts has been received.");
	Console.WriteLine();
}

And one which uses JsonSerializer.DeserializeAsyncEnumerable to deserialize the stream.

private static async Task NegotiateJsonStreamAsync()
{
	Console.WriteLine($"-- {nameof(NegotiateJsonStreamAsync)} --");
	Console.WriteLine($"[{DateTime.UtcNow:hh:mm:ss.fff}] Receving weather forecasts . . .");

	using HttpClient httpClient = new();
	httpClient.DefaultRequestHeaders.Add("Accept", "application/json");

	using HttpResponseMessage response = await httpClient.GetAsync("https://localhost:5001/api/WeatherForecasts/negotiate-stream", HttpCompletionOption.ResponseHeadersRead).ConfigureAwait(false);

	response.EnsureSuccessStatusCode();

	using Stream responseStream = await response.Content.ReadAsStreamAsync().ConfigureAwait(false);
	await foreach (WeatherForecast weatherForecast in JsonSerializer.DeserializeAsyncEnumerable<WeatherForecast>(responseStream, new JsonSerializerOptions { PropertyNameCaseInsensitive = true, DefaultBufferSize = 128 }))
	{
		Console.WriteLine($"[{DateTime.UtcNow:hh:mm:ss.fff}] {weatherForecast.Summary}");
	}

	Console.WriteLine($"[{DateTime.UtcNow:hh:mm:ss.fff}] Weather forecasts has been received.");
	Console.WriteLine();
}

The output from the first one is as follows.

-- NegotiateRawJsonStreamAsync --
[10:35:18.041] Receving weather forecasts . . .
[10:35:18.075] (1/16384) [
[10:35:18.184] (89/16384) {"dateFormatted":"22.07.2021","temperatureC":49,"temperatureF":120,"summary":"Scorching"}
[10:35:18.286] (89/16384) ,{"dateFormatted":"23.07.2021","temperatureC":-20,"temperatureF":-3,"summary":"Freezing"}
[10:35:18.396] (91/16384) ,{"dateFormatted":"24.07.2021","temperatureC":49,"temperatureF":120,"summary":"Sweltering"}
[10:35:18.504] (88/16384) ,{"dateFormatted":"25.07.2021","temperatureC":-18,"temperatureF":0,"summary":"Freezing"}
[10:35:18.612] (84/16384) ,{"dateFormatted":"26.07.2021","temperatureC":30,"temperatureF":85,"summary":"Cool"}
[10:35:18.719] (86/16384) ,{"dateFormatted":"27.07.2021","temperatureC":5,"temperatureF":40,"summary":"Bracing"}
[10:35:18.830] (87/16384) ,{"dateFormatted":"28.07.2021","temperatureC":-6,"temperatureF":22,"summary":"Bracing"}
[10:35:18.952] (84/16384) ,{"dateFormatted":"29.07.2021","temperatureC":13,"temperatureF":55,"summary":"Warm"}
[10:35:19.075] (85/16384) ,{"dateFormatted":"30.07.2021","temperatureC":34,"temperatureF":93,"summary":"Balmy"}
[10:35:19.185] (85/16384) ,{"dateFormatted":"31.07.2021","temperatureC":36,"temperatureF":96,"summary":"Warm"}]
[10:35:19.204] (0/16384)
[10:35:19.212] Weather forecasts has been received.

Which confirms that ASP.NET Core is flushing the results as they come.

The output from the second is as follows.

-- NegotiateJsonStreamAsync --
[10:35:19.218] Receving weather forecasts . . .
[10:35:20.361] Bracing
[10:35:20.362] Mild
[10:35:20.363] Sweltering
[10:35:20.363] Balmy
[10:35:20.363] Bracing
[10:35:20.363] Bracing
[10:35:20.363] Sweltering
[10:35:20.364] Hot
[10:35:20.364] Balmy
[10:35:20.364] Sweltering
[10:35:20.364] Weather forecasts has been received.

This suggest that JsonSerializer.DeserializeAsyncEnumerable is waiting for the entire stream before it starts deserializing.

I haven't found this explained in documentation, so my question would be if this is expected behavior or am I doing something wrong?

The project where I'm plaining with this is available here.

Author: tpeczek
Assignees: -
Labels:

area-System.Net.Http, untriaged

Milestone: -

@ghost
Copy link

ghost commented Jul 21, 2021

Tagging subscribers to this area: @eiriktsarpalis, @layomia
See info in area-owners.md if you want to be subscribed.

Issue Details

Hi,

I have a question around JsonSerializer.DeserializeAsyncEnumerable. I was experimenting with async streaming between ASP.NET Core and HttpClient in .NET 6. I have created two methods on the client side. One which outputs the raw data returned by the ASP.NET Core endpoint.

private static async Task NegotiateRawJsonStreamAsync()
{
	Console.WriteLine($"-- {nameof(NegotiateRawJsonStreamAsync)} --");
	Console.WriteLine($"[{DateTime.UtcNow:hh:mm:ss.fff}] Receving weather forecasts . . .");

	using HttpClient httpClient = new();
	httpClient.DefaultRequestHeaders.Add("Accept", "application/json");

	using HttpResponseMessage response = await httpClient.GetAsync("https://localhost:5001/api/WeatherForecasts/negotiate-stream", HttpCompletionOption.ResponseHeadersRead).ConfigureAwait(false);

	response.EnsureSuccessStatusCode();
	using Stream responseStream = await response.Content.ReadAsStreamAsync().ConfigureAwait(false);

	while (true)
	{
		byte[] buffer = ArrayPool<byte>.Shared.Rent(128);
		int bytesRead = await responseStream.ReadAsync(buffer);

		Console.WriteLine($"[{DateTime.UtcNow:hh:mm:ss.fff}] ({bytesRead}/{buffer.Length}) {Encoding.UTF8.GetString(buffer)}");

                ArrayPool<byte>.Shared.Return(buffer);

		if (bytesRead == 0)
		{
			break;
		}
	}

	Console.WriteLine($"[{DateTime.UtcNow:hh:mm:ss.fff}] Weather forecasts has been received.");
	Console.WriteLine();
}

And one which uses JsonSerializer.DeserializeAsyncEnumerable to deserialize the stream.

private static async Task NegotiateJsonStreamAsync()
{
	Console.WriteLine($"-- {nameof(NegotiateJsonStreamAsync)} --");
	Console.WriteLine($"[{DateTime.UtcNow:hh:mm:ss.fff}] Receving weather forecasts . . .");

	using HttpClient httpClient = new();
	httpClient.DefaultRequestHeaders.Add("Accept", "application/json");

	using HttpResponseMessage response = await httpClient.GetAsync("https://localhost:5001/api/WeatherForecasts/negotiate-stream", HttpCompletionOption.ResponseHeadersRead).ConfigureAwait(false);

	response.EnsureSuccessStatusCode();
	using Stream responseStream = await response.Content.ReadAsStreamAsync().ConfigureAwait(false);

	await foreach (WeatherForecast weatherForecast in JsonSerializer.DeserializeAsyncEnumerable<WeatherForecast>(responseStream, new JsonSerializerOptions { PropertyNameCaseInsensitive = true, DefaultBufferSize = 128 }))
	{
		Console.WriteLine($"[{DateTime.UtcNow:hh:mm:ss.fff}] {weatherForecast.Summary}");
	}

	Console.WriteLine($"[{DateTime.UtcNow:hh:mm:ss.fff}] Weather forecasts has been received.");
	Console.WriteLine();
}

The output from the first one is as follows.

-- NegotiateRawJsonStreamAsync --
[10:35:18.041] Receving weather forecasts . . .
[10:35:18.075] (1/128) [
[10:35:18.184] (89/128) {"dateFormatted":"22.07.2021","temperatureC":49,"temperatureF":120,"summary":"Scorching"}
[10:35:18.286] (89/128) ,{"dateFormatted":"23.07.2021","temperatureC":-20,"temperatureF":-3,"summary":"Freezing"}
[10:35:18.396] (91/128) ,{"dateFormatted":"24.07.2021","temperatureC":49,"temperatureF":120,"summary":"Sweltering"}
[10:35:18.504] (88/128) ,{"dateFormatted":"25.07.2021","temperatureC":-18,"temperatureF":0,"summary":"Freezing"}
[10:35:18.612] (84/128) ,{"dateFormatted":"26.07.2021","temperatureC":30,"temperatureF":85,"summary":"Cool"}
[10:35:18.719] (86/128) ,{"dateFormatted":"27.07.2021","temperatureC":5,"temperatureF":40,"summary":"Bracing"}
[10:35:18.830] (87/128) ,{"dateFormatted":"28.07.2021","temperatureC":-6,"temperatureF":22,"summary":"Bracing"}
[10:35:18.952] (84/128) ,{"dateFormatted":"29.07.2021","temperatureC":13,"temperatureF":55,"summary":"Warm"}
[10:35:19.075] (85/128) ,{"dateFormatted":"30.07.2021","temperatureC":34,"temperatureF":93,"summary":"Balmy"}
[10:35:19.185] (85/128) ,{"dateFormatted":"31.07.2021","temperatureC":36,"temperatureF":96,"summary":"Warm"}]
[10:35:19.204] (0/128)
[10:35:19.212] Weather forecasts has been received.

Which confirms that ASP.NET Core is flushing the results as they come.

The output from the second is as follows.

-- NegotiateJsonStreamAsync --
[10:35:19.218] Receving weather forecasts . . .
[10:35:20.361] Bracing
[10:35:20.362] Mild
[10:35:20.363] Sweltering
[10:35:20.363] Balmy
[10:35:20.363] Bracing
[10:35:20.363] Bracing
[10:35:20.363] Sweltering
[10:35:20.364] Hot
[10:35:20.364] Balmy
[10:35:20.364] Sweltering
[10:35:20.364] Weather forecasts has been received.

This suggest that JsonSerializer.DeserializeAsyncEnumerable is waiting for the entire stream before it starts deserializing.

I haven't found this explained in documentation, so my question would be if this is expected behavior or am I doing something wrong?

The project where I'm plaining with this is available here.

Author: tpeczek
Assignees: -
Labels:

area-System.Text.Json, untriaged

Milestone: -

@ghost ghost added the in-pr There is an active PR which will close this issue when it is merged label Jul 21, 2021
@eiriktsarpalis
Copy link
Member

Hi @tpeczek, thanks for reporting this issue. It's a regression introduced by #51702. I have submitted #56080 that should fix the bug.

@eiriktsarpalis eiriktsarpalis added bug and removed untriaged New issue has not been triaged by the area owner labels Jul 21, 2021
@eiriktsarpalis eiriktsarpalis added this to the 6.0.0 milestone Jul 21, 2021
@eiriktsarpalis eiriktsarpalis self-assigned this Jul 21, 2021
@tpeczek
Copy link
Author

tpeczek commented Jul 21, 2021

Hi @eiriktsarpalis , thank you for taking a look at this. My only two questions would be if there is a chance that fix is going to make it into Preview 7, and are there past previews which have the correct behavior?

@eiriktsarpalis
Copy link
Member

Once merged the fix would be committed to the RC1 branch and not Preview 7. I believe preview4 might not incorporate the regression although that release is no longer supported.

@tpeczek
Copy link
Author

tpeczek commented Jul 21, 2021

Thank you!

@ghost ghost removed the in-pr There is an active PR which will close this issue when it is merged label Jul 22, 2021
@ghost ghost locked as resolved and limited conversation to collaborators Aug 21, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants