C# .NET Core 3.1 - Driver (2.11.1) - Slow ToList() data manifestation

Andrea_Zanini · 2020-09-09T21:36:44.097Z

I don’t think so. I am running all locally (mongodb is hosted in localhost:27017). All C# in a basic Console Application project with no client side.
I am doing like this just to understand the MongoDb C# Driver.

So I don’t really know.

Joe_Drumgoole · 2020-09-10T08:23:34.746Z

Put a time stamp either side of the query on the client. It may just take a while to start your program. How long does it take from the program side to run the query.

Andrea_Zanini · 2020-09-10T12:34:01.214Z

So, as I wrote I am doing this in a ConsoleApplication NetcoreApp 3.1.
I executed 2 different ways of querying, one with FindSync() the other with Aggregate().Match().

The first one (FindSync):

Capture1672×494 10.4 KB

The second one (Aggregate):

Capture11628×485 10.8 KB

Joe_Drumgoole · 2020-09-11T08:56:37.720Z

I am going to ask my C# colleague @yo_adrienne to take a look. She is based in Nevada so it will be a few hours.

yo_adrienne · 2020-09-16T23:03:09.807Z

Hi @Andrea_Zanini!

Can you try your queries but with ToListAsync()?

And if possible, can you also log out the execution stats?

Andrea_Zanini · 2020-09-26T08:16:47.046Z

Hello, sorry for the late answer.

I tried the same thing with the await query.ToListAsync(); but even with that the time it takes for manifest the data is the same.

For the execution stats do you mean what @Joe_Drumgoole asked me? Or I can, with C# code, somehow use the execution stats for the ToListAsync() operation?

Sergio_Fiorillo · 2020-12-02T22:03:34.847Z

Hi All,

I am experiencing the same issue. It’s not a matter of a big number of documents retrieved by the query but when doing the tolist(), it takes around 20 seconds to materialize them. Do you have any workaround or estimation for the fix? We also tried with the newest mongoDb driver version, but the issue is still there either using tolist or toListAsync. Please help

Andrea_Zanini · 2020-12-03T15:57:49.517Z

Hello Sergio,
I didn’t found the cause of the problem and how to solve it unfortunately.

What I did to go on with the project was start from the scratch and rebuild my document class with all the BsonAttribute to define via code what type are the property of the document (even if, when declared, have already the type)
Example:

public class Example {
    [BsonId]
    [BsonRepresentation(BsonType.ObjectId)]
    public Guid Id {get; set; }
    
    [BsonRepresentation(BsonType.String)]
    public string Name {get; set; }
}

I changed a lot, more that I wanted to my document, but now the manifestation time it’s what I expected to be.

I didn’t close the issue because I think there is something spooky around it.

Sergio_Fiorillo · 2020-12-03T18:58:21.657Z

Hi Andrea,

Thanks for your response. I tried that but still having the same issue toList is extremely slow:

        var query = collection.Aggregate(new AggregateOptions { AllowDiskUse = true })
            .Match(matching_criteria)
            .Group(grouping_criteria)
            .Sort(sorting_criteria)
            .Project(projection)
            .As<DOCUMENT>();

        var result = query.ToList();

Any other ideas on this?

Joao_Passos · 2021-03-09T16:28:44.669Z

Hi,

I’m experiencing a similar performance overhead with the client for 1667 results.
Time in Compass : Actual Query Execution Time (ms):120
C# driver: around 6000 ms

Any update on this?

Joe_Drumgoole · 2021-03-10T09:40:18.159Z

I am going to get some C# experts to check this one out.

Joao_Passos · 2021-03-10T10:42:46.215Z

In my case, the time seems to be in the serialization
It’s returning 1667 instances of Entity, each one with 500 instances of Bar and 150 instances of Foo

   public class Entity
{
	public Guid Id { get; set; }
	public List<Bar> BarValues { get; set; }
	public List<Foo> FooValues { get; set; }
}

public class Bar
{
	public Guid Id { get; set; }
	public Guid B { get; set; }
	public Guid C { get; set; }
}

public class Foo
{
	public Guid Id { get; set; }
	public Guid B { get; set; }
	public object C { get; set; }
}

yo_adrienne · 2021-03-10T21:45:39.148Z

@Andrea_Zanini, @Sergio_Fiorillo, @Joao_Passos:

There are still many factors that could be affecting these times, so I’d like to ask a few more questions regarding your respective scenarios:

What is your ping time?
What’s the bandwidth between your client and your MongoDB cluster?

The object models collectively posted here seem straightforward, so the deserialization shouldn’t be an issue.

Additionally, regarding these observations:

Andrea_Zanini:

The result of the query operation in MongoDbCompass is 1ms for 200 document and its super ok.
The result of the ToList() of the documents is 10 seconds .

Joao_Passos:

Time in Compass : Actual Query Execution Time (ms):120
C# driver: around 6000 ms

I’d like to quickly explain why this may be:

When making a call to db.GetCollection(), this is usually ~8ms, as @Andrea_Zanini’s screenshots show:

Andrea_Zanini:

The first one (FindSync):

Capture1672×494 10.4 KB

The second one (Aggregate):

Capture11628×485 10.8 KB

When creating the Aggregate queries, it’s important to note that this doesn’t result in the first batch being retrieved; it’s only in-memory and doesn’t go out on the wire yet. Calling query.ToList(); takes the longest now because it has to retrieve the first batch (~600ms based on the FindSync log in Andrea’s first screenshot), PLUS all subsequent batches. This is why the total times are 8.5 seconds or higher.

Compass reports query execution time is only 120ms because that only considers the query time on the server. It doesn’t include the time on the wire nor the deserialization from BSON to C# objects.

So, some options:

If you find that ping time is your bottleneck, your wait time is probably due to the amount of roundtrips that are required to retrieve the batches. Based on the earlier example of 9.1 seconds grand total execution time and ~600ms per batch, that’s about 15 round trips to the server (9.1s / 600ms).

Possible solution to ping issue is to locate your app servers closer to the cluster that you’re querying.

If you find that bandwidth is your bottleneck, your wait time is probably due to the time it takes to transmit each 15mb batch across the wire, again, around 15 times.

Possible solution to bandwidth issue is to reduce the amount of data being retrieved, via a projection (like @Sergio_Fiorillo appears to be doing), and/or enabling wire protocol compression in your connection string or via code.

Finally, if all else fails and it still appears to be a deserialization issue, we’d love to see a reproduction of it happening, ideally with some test data. I know it might be additional work, but even a small repo with this information helps us immensely in being able to debug the exact issue you may be having!

Thanks for your patience! Looking forward to hearing from you and seeing if these possible solutions help.

Joao_Passos · 2021-03-12T12:41:18.002Z

Hi,

Thank you for the prompt support.
The object models are more complex than the simplified version I posted
I have MongoDB running on my local machine so bandwidth is not an issue.

Here’s a repo with a working example: https://github.com/jpdlpassos/mongodb

5000 raw values took 675 ms
5000 typed values took 14461 ms

Hopefully, you can help me spot where i can improve my code.

Thanks again!

Joao_Passos · 2021-03-17T09:39:13.677Z

Hi,

could you have a look at the repo?
any doubt i can clarify?

Thanks!

yo_adrienne · 2021-03-18T00:18:41.769Z

Hi @Joao_Passos!

I have cloned your repo and have been trying to debug the situation. I was also able to reproduce your issue, so I’ve pulled in a few of the driver engineers to see if they can help me debug further!

I’ll continue to post here when I have any meaningful updates. In the meantime, thank you for your patience while we figure this out!

Sergio_Fiorillo · 2021-03-26T12:42:39.755Z

Hi! Thanks for all your analysis @yo_adrienne

In my case, after lot of hours of research and work we concluded it was not the toList() what was wrong in our application. It was a little bit of everything… apart from the bandwith potential delays we had for sure, we were retrieving a lot of data - around 13MB on some particular scenario - from the database and there was the bottleneck. We had to change a litte bit our model by implementing the bucket pattern in the first place. Then we also made changes on our aggregate queries by setting lookups properly using the needed projections there as well.

After all those changes now it works as expected.

Thanks a lot!

yo_adrienne · 2021-03-26T16:19:56.736Z

That is so awesome to hear @Sergio_Fiorillo! Thanks for coming back and posting about it as it helps others as well

yo_adrienne · 2021-03-31T02:13:01.091Z

@Joao_Passos an update!

TL;DR: Most of the performance hit is due to dealing with the complexity of the Facility objects.

Longer version:

After spending quite some time with the .NET driver team, we’ve found the following:

Instantiation of 5000 Facility objects alone takes about 2 seconds. This is pure C# without the driver involved at all.
Comparing the performance of RawBsonDocument to Facility objects isn’t really an equal or fair comparison (more on that below).
Taking the sample repo you’ve shared with us, most of the time is spent on traversing 5000 facilities objects with 150 parameters each and 500 attributes each; that’s about 4.75 million in-memory objects!

Why comparing performance of RawBsonDocument to Facility object is not an equal comparison,
as explained by one of our Sr. .NET driver engineers:

Comparing the performance of RawBsonDocument to Facility objects isn’t exactly a fair comparison as we wrap the raw payload in an object but don’t iterate it or deserialize it into objects. So we are comparing time-on-the-wire (RawBsonDocument case) to time-on-the-wire plus deserialization overhead. That said, retrieving the raw BSON bytes and wrapping them in a collection of RawBsonDocuments takes 897ms but deserializing them into C# objects take ~14 seconds.

If we deserialize into BsonDocument (rather than RawBsonDocument ) then we are avoiding the mapping overhead of converting raw BSON bytes into C# objects, but are still reading the bytes to convert into a series of nested BSON documents. Deserializing to BsonDocument takes 12s.

As a final test, we also modified just your Program.cs file from your repo to see if any performance increases could be made. We were able to get some performance increases, but in a “quick and dirty, but gets results done” kind of way:


using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Linq;
using System.Threading.Tasks;
using MongoDB.Bson;
using MongoDB.Bson.Serialization;
using MongoDB.Driver;
namespace mongodb
{
	internal class Program
	{
		private static readonly FacilityAttributeStringValue Country = new()
			{Id = Guid.NewGuid(), AttributeId = Guid.NewGuid(), Value = "Spain"};
		private static async Task Main(string[] args)
		{
			BsonClassMap.RegisterClassMap<FacilityAttributeDateTimeValue>();
			BsonClassMap.RegisterClassMap<FacilityAttributeStringValue>();
			BsonClassMap.RegisterClassMap<FacilityAttributeDecimalValue>();
			BsonClassMap.RegisterClassMap<MonitoredDataSourceId>();
			BsonClassMap.RegisterClassMap<CustomDataSourceId>();
			var client =
				new MongoClient(
					"mongodb://localhost:27017/?readPreference=primary&appname=mongodb-vscode%200.4.1&ssl=false");
			await client.DropDatabaseAsync("mongo-benchmark");
			var db = client.GetDatabase("mongo-benchmark");
			var typedCollection = db.GetCollection<Facility>("facilities");
			//Insert 5000 facilities with 150 parameter and 500 attributes each
			var sw = Stopwatch.StartNew();
			var facilities = GetFacilities().ToList();
			sw.Stop();
			Console.WriteLine($"Created 5000 facilities in {sw.ElapsedMilliseconds} ms.");
			await typedCollection.InsertManyAsync(facilities);
            //Bson
			var bsonCollection = db.GetCollection<BsonDocument>("facilities");
			sw.Restart();
            var bsonValues = await (await bsonCollection
                .FindAsync(new BsonDocumentFilterDefinition<BsonDocument>(new BsonDocument()))).ToListAsync();
			sw.Stop();
			Console.WriteLine(bsonValues.Count + " BSON values took " + sw.ElapsedMilliseconds);
            //RawBson
			var rawCollection = db.GetCollection<RawBsonDocument>("facilities");
			sw.Restart();
            var rawValues = await (await rawCollection
                .FindAsync(new BsonDocumentFilterDefinition<RawBsonDocument>(new BsonDocument()))).ToListAsync();
			sw.Stop();
			Console.WriteLine(rawValues.Count + " raw values took " + sw.ElapsedMilliseconds);
            sw.Restart();
            foreach (var doc in rawValues)
            {
                foreach (var field in doc.Elements)
                {
                    switch (field.Name)
                    {
                        case "_id":
                            var id = field.Value;
                            break;
                        default:
                            foreach (var elem in (RawBsonArray)field.Value)
                            {
                                var value = elem.AsBsonValue;
                            }
                            break;
                    }
                }
            }
            sw.Stop();
			Console.WriteLine($"Iterating the raw BSON took {sw.ElapsedMilliseconds} ms.");
			//Typed
			sw.Restart();
			var typedValues = await (await typedCollection.FindAsync(new BsonDocument())).ToListAsync();
			sw.Stop();
			Console.WriteLine(typedValues.Count + " typed values took " + sw.ElapsedMilliseconds);
		}
		private static IEnumerable<Facility> GetFacilities()
		{
			var parameter = Enumerable.Range(0, 150).Select(_ => Guid.NewGuid()).ToList();
			var attributes = Enumerable.Range(0, 500).Select(_ => Guid.NewGuid()).ToList();
			for (var i = 0; i < 5000; i++)
				yield return new Facility
				{
					Id = Guid.NewGuid(),
					ParametersValues = parameter.Select(p => new ParameterValue
					{
						Id = Guid.NewGuid(),
						ParameterId = p,
						DataSourceId = new CustomDataSourceId {Id = Guid.NewGuid()}
					}).ToList(),
					AttributesValues =
						i % 3 == 0
							? new List<AttributeValue>(attributes.Take(499).Select(a =>
								new FacilityAttributeStringValue
									{Id = Guid.NewGuid(), AttributeId = a, Value = a.ToString()}).Append(Country))
							: new List<AttributeValue>(attributes.Select(a =>
								new FacilityAttributeStringValue
									{Id = Guid.NewGuid(), AttributeId = a, Value = a.ToString()}))
				};
		}
	}
}

Those changes resulted in these benchmarks:

Created 5000 facilities in 3229 ms.
5000 BSON values took 16468
5000 raw values took 1014
Iterating the raw BSON took 3627 ms.
5000 typed values took 16698

So while the total time of about 16.7 seconds is longer than we’d like, it’s only twice as slow as the component parts, not 16x slower.

For reference:

Retrieving raw BSON: ~1 second
Traversing raw BSON: 3.6 seconds
Instantiating all C# objects: 3.2 seconds

which means best case scenario = 7.8 seconds without the class maps or other deserialization infrastructure involved.

I hope this helps better explain why you may be experiencing this expected delay with the objects you have!

system · 2021-04-05T02:13:07.024Z

This topic was automatically closed 5 days after the last reply. New replies are no longer allowed.