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

Diagnostics: DataReaderDisposingEventData.ReadCount accumulates the value from different readers #27652

Closed
arekpalinski opened this issue Mar 16, 2022 · 3 comments · Fixed by #27845
Assignees
Labels
area-query closed-fixed The issue has been fixed and is/will be included in the release indicated by the issue milestone. customer-reported regression Servicing-approved type-bug
Milestone

Comments

@arekpalinski
Copy link

It looks that in the DataReaderDisposingEventData.ReadCount accumulates the values from different readers.

Include your code

I have the following diagnostics observer:

public class MyObserver : IObserver<KeyValuePair<string, object>>
        {
            public void OnCompleted()
            {

            }

            public void OnError(Exception error)
            {

            }

            public void OnNext(KeyValuePair<string, object> item)
            {
                var value = item.Value;
                var key = item.Key;

                if (value is DataReaderDisposingEventData data)
                {
                    Console.WriteLine(data.ReadCount);
                }
            }
        }


        public class MyDiagnosticListenerObserver : IObserver<DiagnosticListener>
        {
            private readonly MyObserver _observer;

            internal MyDiagnosticListenerObserver(MyObserver observer)
            {
                this._observer = observer;
            }

            public void OnCompleted()
            {

            }

            public void OnError(Exception error)
            {

            }

            public void OnNext(DiagnosticListener value)
            {
                value.Subscribe(_observer);
            }
        }

Diagnostics initialization:

MyDiagnosticListenerObserver myDiagnosticListenerObserver = new MyDiagnosticListenerObserver(new MyObserver());
DiagnosticListener.AllListeners.Subscribe(myDiagnosticListenerObserver);

Sample code using EF (select n+1 problem):

using (var db = new Entities(conStr))
{
	foreach (var post in db.Posts.ToList())
	{
		db.Entry(post).Collection(p => p.Comments).Load();
	}
}

The above code writes the following (expected) output to the console when using EF Core version: 5.0.15:

11
5
5
5
5
5
5
5
5
5
5

while the same code using EF Core 6.0.3 outputs the following:

11
16
21
26
31
36
41
46
51
56
61
@roji roji added the type-bug label Mar 16, 2022
@roji roji self-assigned this Mar 16, 2022
@ajcvickers ajcvickers added this to the 7.0.0 milestone Mar 22, 2022
@arekpalinski
Copy link
Author

I see it was tagged by 7.0.0 milestone. This is pretty important for us since this affects our product (Entity Framework Profiler - https://hibernatingrhinos.com/products/efprof) and users get incorrect results when profiling their applications. We don't have a way to workaround this issue. Can this be considered to be fixed in 6.0.x version?

@ajcvickers ajcvickers modified the milestone: 7.0.0 Mar 25, 2022
@ajcvickers ajcvickers added this to the 6.0.x milestone Apr 1, 2022
@roji roji changed the title Diagnostics: DataReaderDisposingEventData.ReadCount accumulates the value from different readers in EF Core 6.0.3 Diagnostics: DataReaderDisposingEventData.ReadCount accumulates the value from different readers Apr 20, 2022
roji added a commit to roji/efcore that referenced this issue Apr 20, 2022
@roji
Copy link
Member

roji commented Apr 20, 2022

@arekpalinski thanks, I've verified and fixed this - as part of the EF Core 6.0 query perf optimization cycle, RelationalDataReader started to get recycled across executions, but the read count value wasn't properly reset.

This seems like a good candidate for servicing for 6.0 (safe one-line change), we'll discuss it.

@arekpalinski
Copy link
Author

Thank you. Yeah, I would be really great for us to have it in 6.0 since it affects our customers.

roji added a commit that referenced this issue Apr 21, 2022
@roji roji reopened this Apr 21, 2022
roji added a commit to roji/efcore that referenced this issue Apr 21, 2022
roji added a commit to roji/efcore that referenced this issue Apr 21, 2022
@AndriySvyryd AndriySvyryd modified the milestones: 6.0.x, 6.0.6 May 7, 2022
@AndriySvyryd AndriySvyryd added the closed-fixed The issue has been fixed and is/will be included in the release indicated by the issue milestone. label May 7, 2022
@ghost ghost closed this as completed in 282fe31 May 11, 2022
This issue was closed.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area-query closed-fixed The issue has been fixed and is/will be included in the release indicated by the issue milestone. customer-reported regression Servicing-approved type-bug
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants