Aggregating slowing down considerably while using Java drivers

khat33b · 2021-09-03T10:46:47.723Z

Previously, my MongoDB aggregations were being run using the NodeJS driver. But our project was decided to shift to Java. After transferring, the aggregation is taking around 2 minutes for each while in NodeJS it was done in under a second. I have even tried to explain the execution plan but could not get any info as why this is happening. This delay is happening even if the aggregation is a simple projection.

My driver is:

    implementation group: 'org.mongodb', name: 'mongodb-driver-sync', version: '4.3.1'
    implementation group: 'org.mongodb', name: 'bson', version: '4.3.1'

My code is:

public static List<JsonObject> aggregateCollectionPhysicalFlattened(String collectionName, List<? extends Bson> pipeline, int batchSize) {
	System.out.println("Aggregating " + collectionName);
	try (MongoClient mongoClient = MongoClients.create(getMongoClientSettings())) {
		MongoDatabase db = mongoClient.getDatabase(DATABASE_DIGITAL_SOURCE);
		MongoCollection collection = db.getCollection(collectionName);
		long startTime = System.currentTimeMillis();
		AggregateIterable mongoIterable = collection.withDocumentClass(JsonObject.class)
				.aggregate(pipeline);
		long elapsedTime = System.currentTimeMillis() - startTime;
		System.out.println("elapsedTime aggregate: " + elapsedTime);
		Document explanation = mongoIterable.explain(ExplainVerbosity.ALL_PLANS_EXECUTIONS);
		List<Document> stages = explanation.get("stages", List.class);
		List<String> keys = Arrays.asList("queryPlanner", "winningPlan");
		for (Document stage : stages) {
			Document cursorStage = stage.get("$cursor", Document.class);
			if (cursorStage != null) {
				System.out.println(cursorStage.getEmbedded(keys, Document.class).toJson());
			}
		}
		startTime = System.currentTimeMillis();
		List<JsonObject> results = (List<JsonObject>) mongoIterable.batchSize(batchSize).into(new ArrayList<>());
		elapsedTime = System.currentTimeMillis() - startTime;
		System.out.println("elapsedTime into: " + elapsedTime);
		return results;
	} catch(Exception e) {
		e.printStackTrace();
	}
	return null;
}

A sample projection which needs 2 minutes to run:

[
  {
    "$project":{
      "upc":1,
      "inventory_name":1,
      "street_date":1,
      "format":1,
      "sub_studio":1,
      "us_base":1,
      "us_srp":1,
      "disc_num":1,
      "modified_date":1
    }
  }
]

The result of the explain function:

{
  "stage": "PROJECTION_SIMPLE",
  "transformBy": {
    "cidm_retailer_type": 1,
    "date_sk": 1,
    "extd_price": 1,
    "format": 1,
    "inventory_name": 1,
    "invoice_id": 1,
    "qty": 1,
    "retailer_id": 1,
    "retailer_name": 1,
    "street_date": 1,
    "sub_studio": 1,
    "upc": 1,
    "_id": 0
  },
  "inputStage": {
    "stage": "COLLSCAN",
    "direction": "forward"
  }
}

I have found that the main line which causes the slowdown is when converting the Iterable to an ArrayList. This line:

List results = (List) mongoIterable.batchSize(batchSize).into(new ArrayList<>());

How do I make it run as fast as NodeJS?

Asya_Kamsky · 2021-09-03T16:57:31.902Z

Can you run the same aggregation with js and with java and look at the mongod logs (the log line for that aggregation)? You may need to increase logging verbosity to get both or turn on profiling. What that will show you is how much time is spent in the database doing the query. If the time is spent in the Java language then it’s not really something explain or database tuning can help with.

Also the code above is running explain - you should be measuring how long a regular query/aggregation takes as explain itself adds overhead. Can you provide your sample Java code that shows slowness of the query (without explain)?

Asya_Kamsky · 2021-09-03T17:00:41.211Z

Also are you sure it’s converting results to list that’s the issue? It looks like you are converting things to JsonObjects, how long does it take if you just return results to List<Document> results and iterate over that?

steevej · 2021-09-04T11:12:27.478Z

It would be interesting to see the JS code.

This way we could be sure you are really doing the same thing. For example if you do not iterate the cursor you do not download any documents from the server.

khat33b · 2021-09-07T11:26:04.597Z

@Asya_Kamsky @steevej

This is my log with Java:

{"t":{"$date":"2021-09-07T10:03:17.484+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn20","msg":"Slow query","attr":{"type":"command","ns":"bird.statement","command":{"explain":{"aggregate":"statement","pipeline":[{"$group":{"_id":{"invoice_id":"$invoice_id","upc1":"$upc","retailer_id":"$retailer_id"},"qty":{"$sum":"$qty"},"revenue":{"$sum":"$extd_price"},"date_sk":{"$first":"$date_sk"},"inventory_name":{"$first":"$inventory_name"},"format":{"$first":"$format"},"sub_studio":{"$first":"$sub_studio"},"street_date":{"$first":"$street_date"},"retailer_id":{"$first":"$retailer_id"},"retailer_name":{"$first":"$retailer_name"},"retailer_type":{"$first":"$cidm_retailer_type"}}},{"$group":{"_id":{"upc1":"$_id.upc1","retailer_id":"$_id.retailer_id"},"invoices":{"$push":{"invoice_id":"$_id.invoice_id","qty":"$qty","revenue":"$revenue"}},"upc":{"$first":"$_id.upc1"},"date_sk":{"$first":"$date_sk"},"inventory_name":{"$first":"$inventory_name"},"format":{"$first":"$format"},"sub_studio":{"$first":"$sub_studio"},"street_date":{"$first":"$street_date"},"retailer_id":{"$first":"$retailer_id"},"retailer_name":{"$first":"$retailer_name"},"retailer_type":{"$first":"$retailer_type"}}}],"cursor":{}},"verbosity":"allPlansExecution","$db":"bird","lsid":{"id":{"$uuid":"4571756a-cb1a-4c46-ba1e-a976e1666f30"}}},"planSummary":"COLLSCAN","numYields":33,"reslen":4898,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"r":37}},"Database":{"acquireCount":{"r":1}},"Collection":{"acquireCount":{"r":1}},"Mutex":{"acquireCount":{"r":4}}},"storage":{"data":{"bytesRead":39848460,"timeReadingMicros":65875}},"remote":"103.242.190.99:63628","protocol":"op_msg","durationMillis":330}}
{"t":{"$date":"2021-09-07T10:03:17.935+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn20","msg":"Slow query","attr":{"type":"command","ns":"bird.statement","command":{"aggregate":"statement","pipeline":[{"$group":{"_id":{"invoice_id":"$invoice_id","upc1":"$upc","retailer_id":"$retailer_id"},"qty":{"$sum":"$qty"},"revenue":{"$sum":"$extd_price"},"date_sk":{"$first":"$date_sk"},"inventory_name":{"$first":"$inventory_name"},"format":{"$first":"$format"},"sub_studio":{"$first":"$sub_studio"},"street_date":{"$first":"$street_date"},"retailer_id":{"$first":"$retailer_id"},"retailer_name":{"$first":"$retailer_name"},"retailer_type":{"$first":"$cidm_retailer_type"}}},{"$group":{"_id":{"upc1":"$_id.upc1","retailer_id":"$_id.retailer_id"},"invoices":{"$push":{"invoice_id":"$_id.invoice_id","qty":"$qty","revenue":"$revenue"}},"upc":{"$first":"$_id.upc1"},"date_sk":{"$first":"$date_sk"},"inventory_name":{"$first":"$inventory_name"},"format":{"$first":"$format"},"sub_studio":{"$first":"$sub_studio"},"street_date":{"$first":"$street_date"},"retailer_id":{"$first":"$retailer_id"},"retailer_name":{"$first":"$retailer_name"},"retailer_type":{"$first":"$retailer_type"}}}],"cursor":{"batchSize":5},"$db":"bird","lsid":{"id":{"$uuid":"4571756a-cb1a-4c46-ba1e-a976e1666f30"}}},"planSummary":"COLLSCAN","cursorid":2723224898395150748,"keysExamined":0,"docsExamined":33102,"numYields":33,"nreturned":5,"reslen":1990,"locks":{"Global":{"acquireCount":{"r":36}},"Mutex":{"acquireCount":{"r":3}}},"storage":{},"remote":"103.242.190.99:63628","protocol":"op_msg","durationMillis":182}}
{"t":{"$date":"2021-09-07T10:03:30.236+00:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"Checkpointer","msg":"WiredTiger message","attr":{"message":"[1631009010:236699][445:0x7fc2bd773700], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 1177, snapshot max: 1177 snapshot count: 0, oldest timestamp: (0, 0) , meta checkpoint timestamp: (0, 0) base write gen: 1073601"}}

For my log in JS, there is no log as such. Only the connection and auth succeed log.

{"t":{"$date":"2021-09-07T11:15:45.430+00:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn21","msg":"client metadata","attr":{"remote":"103.242.190.99:63439","client":"conn21","doc":{"driver":{"name":"nodejs","version":"3.6.5"},"os":{"type":"Windows_NT","name":"win32","architecture":"x64","version":"10.0.19043"},"platform":"'Node.js v14.16.0, LE (legacy)"}}}
{"t":{"$date":"2021-09-07T11:15:45.686+00:00"},"s":"I",  "c":"ACCESS",   "id":20250,   "ctx":"conn21","msg":"Authentication succeeded","attr":{"mechanism":"SCRAM-SHA-256","speculative":true,"principalName":"jtvAdmin","authenticationDatabase":"admin","remote":"103.242.190.99:63439","extraInfo":{}}}

My code without using explain is pretty much the same and also takes the same amount of time:

public static List<BsonDocument> aggregateCollectionPhysicalFlattened(String collectionName, List<? extends Bson> pipeline, int batchSize) {
	System.out.println("Aggregating " + collectionName);
	try {
		MongoDBConnector mongoDBConnector = MongoDBConnector.getInstance();
		MongoDatabase db = mongoDBConnector.getDatabase(DATABASE_BIRD);
		MongoCollection collection = db.getCollection(collectionName);
		long startTime = System.currentTimeMillis();
		AggregateIterable mongoIterable = collection.aggregate(pipeline);
		long elapsedTime = System.currentTimeMillis() - startTime;
		System.out.println("elapsedTime aggregate: " + elapsedTime);
		startTime = System.currentTimeMillis();
		List<BsonDocument> results = (List<BsonDocument>) mongoIterable.batchSize(batchSize).into(new ArrayList<>());
		elapsedTime = System.currentTimeMillis() - startTime;
		System.out.println("elapsedTime into: " + elapsedTime);
		return results;
	} catch(Exception e) {
		e.printStackTrace();
	}
	return null;
}

My JS code is below. It uses GraphQL as the API framework.

export default {
    Query: {
      async PerpetualInventory(_, { batchSize, dateFrom, dateTo, studio }) {
        let res = [];
        const matchCond = {};
        if(studio) matchCond.sub_studio = {$in: studio}
        if(dateFrom || dateTo) {
          matchCond.street_date = {};
          if (dateFrom) matchCond.street_date["$gte"] =  new Date(dateFrom);
          if (dateTo) matchCond.street_date["$lt"] =  new Date(dateTo);
        };
        try {
          await client.connect();
          const db = client.db(dbName);
      
          // Get the collection
          const col = db.collection(collName);
          res = await col.aggregate([
            { 
                $match: matchCond 
            },
            {
              $project: {
                upc: 1,
                inventory_name: 1,
                street_date: 1,
                format: 1,
                sub_studio: 1,
                us_base: 1,
                us_srp: 1,
                disc_num: 1,
                modified_date: 1,
                qoh: { $cond: [ {$and : [ { $gte: [ "$modified_date", dateFrom] }, { $lte: [ "$modified_date", dateTo] } ] }, "$qoh", 0 ] },
              }
            }
          ]).limit(batchSize || 500).toArray();
        } catch(err) {
          console.log(err.stack);
        }
        return res;
      },
    }
}

I am 100% sure it is the mongoIterable.into(new ArrayList<>()) line which causes the delay. I have timed every step of the process and it is here when the delay happens. If I don’t iterate over the cursor, the query is done in under a second.

steevej · 2021-09-07T13:17:01.610Z

I am still not convince that it is the same code.

The long query from the log shows a $group while the others are simply $project. So the long query is certainly not the one you shown in the first post.

A $group is a blocking stage meaning that all matched documents needs to be processed. In the JS pipeline you potentially have a $match that selects much less documents.

We cannot tell if you are using the same batchSize, database and collection.

For helping us help you, I suggest that you hard code the Java pipeline as the one shown in the JS code. Remove the $match from the JS code. Hard code, database, collection and batch size in both JS and Java.

Imad_Bouteraa · 2021-09-07T13:37:45.986Z

I definitely agree with @steevej, the java log shows two pipelines, each one containing two $group stages

the into() is the method that triggers the execution of the pipeline, thus the delay is caused by the pipeline, not the into()

khat33b:

mongoIterable.into(new ArrayList<>())

khat33b · 2021-09-07T14:44:08.233Z

@steevej @Imad_Bouteraa You were right. I was running a different aggregation but this problem is happening with all aggregations. When I hardcoded and ran the projection one, I was getting the same result. The batchsize is also not working somehow in the Java. I hardcoded it as 5 and it still gave me all the results.

public static List<BsonDocument> aggregateCollectionPhysicalFlattened(String collectionName, List<? extends Bson> pipeline, int batchSize) {
	System.out.println("Aggregating " + collectionName);
	System.out.println(pipeline);
	try (MongoClient mongoClient = MongoClients.create(getMongoClientSettings())) {
		MongoDatabase db = mongoClient.getDatabase("bird");
		MongoCollection collection = db.getCollection("inventory");
		long startTime = System.currentTimeMillis();
		AggregateIterable mongoIterable = collection.aggregate(pipeline);
		long elapsedTime = System.currentTimeMillis() - startTime;
		System.out.println("elapsedTime aggregate: " + elapsedTime);
		startTime = System.currentTimeMillis();
		List<BsonDocument> results = (List<BsonDocument>) mongoIterable.batchSize(5).into(new ArrayList<>());
		elapsedTime = System.currentTimeMillis() - startTime;
		System.out.println("elapsedTime into: " + elapsedTime);
		return results;
	} catch(Exception e) {
		e.printStackTrace();
	}
	return null;
}

In my Java code, I am also timing the steps. The results of the print statements are:

Aggregating inventory
[{"$project": {“upc”: 1, “inventory_name”: 1, “street_date”: 1, “format”: 1, “sub_studio”: 1, “us_base”: 1, “us_srp”: 1, “disc_num”: 1, “modified_date”: 1}}]
elapsedTime aggregate: 5
elapsedTime into: 284396
elapsedTimeComplete: 285295

khat33b · 2021-09-07T14:47:00.903Z

And the mongod logs for this are:

{"t":{"$date":"2021-09-07T14:37:42.163+00:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"103.242.190.99:62809","uuid":"4742c218-22f3-437a-afb1-bbfc93858d94","connectionId":48,"connectionCount":3}}
{"t":{"$date":"2021-09-07T14:37:42.173+00:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn48","msg":"client metadata","attr":{"remote":"103.242.190.99:62809","client":"conn48","doc":{"driver":{"name":"mongo-java-driver|sync","version":"4.3.1"},"os":{"type":"Windows","name":"Windows 10","architecture":"amd64","version":"10.0"},"platform":"Java/Oracle Corporation/15.0.2+7-27"}}}
{"t":{"$date":"2021-09-07T14:37:42.482+00:00"},"s":"I",  "c":"ACCESS",   "id":20250,   "ctx":"conn48","msg":"Authentication succeeded","attr":{"mechanism":"SCRAM-SHA-256","speculative":true,"principalName":"jtvAdmin","authenticationDatabase":"admin","remote":"103.242.190.99:62809","extraInfo":{}}}
{"t":{"$date":"2021-09-07T14:38:32.545+00:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"Checkpointer","msg":"WiredTiger message","attr":{"message":"[1631025512:545057][445:0x7fc2bd773700], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 1484, snapshot max: 1484 snapshot count: 0, oldest timestamp: (0, 0) , meta checkpoint timestamp: (0, 0) base write gen: 1073601"}}
{"t":{"$date":"2021-09-07T14:39:32.552+00:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"Checkpointer","msg":"WiredTiger message","attr":{"message":"[1631025572:552321][445:0x7fc2bd773700], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 1487, snapshot max: 1487 snapshot count: 0, oldest timestamp: (0, 0) , meta checkpoint timestamp: (0, 0) base write gen: 1073601"}}
{"t":{"$date":"2021-09-07T14:40:32.562+00:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"Checkpointer","msg":"WiredTiger message","attr":{"message":"[1631025632:562493][445:0x7fc2bd773700], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 1489, snapshot max: 1489 snapshot count: 0, oldest timestamp: (0, 0) , meta checkpoint timestamp: (0, 0) base write gen: 1073601"}}
{"t":{"$date":"2021-09-07T14:41:32.570+00:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"Checkpointer","msg":"WiredTiger message","attr":{"message":"[1631025692:570856][445:0x7fc2bd773700], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 1490, snapshot max: 1490 snapshot count: 0, oldest timestamp: (0, 0) , meta checkpoint timestamp: (0, 0) base write gen: 1073601"}}
{"t":{"$date":"2021-09-07T14:42:25.949+00:00"},"s":"I",  "c":"-",        "id":20883,   "ctx":"conn46","msg":"Interrupted operation as its client disconnected","attr":{"opId":1084472}}
{"t":{"$date":"2021-09-07T14:42:25.950+00:00"},"s":"I",  "c":"NETWORK",  "id":22944,   "ctx":"conn46","msg":"Connection ended","attr":{"remote":"103.242.190.99:62805","uuid":"fa0da81f-2deb-4786-b7f7-cd0c9c70d1a4","connectionId":46,"connectionCount":2}}
{"t":{"$date":"2021-09-07T14:42:25.952+00:00"},"s":"I",  "c":"NETWORK",  "id":22944,   "ctx":"conn47","msg":"Connection ended","attr":{"remote":"103.242.190.99:62806","uuid":"52ab9780-4768-47ca-824d-c011a50cde2c","connectionId":47,"connectionCount":1}}
{"t":{"$date":"2021-09-07T14:42:25.956+00:00"},"s":"I",  "c":"NETWORK",  "id":22944,   "ctx":"conn48","msg":"Connection ended","attr":{"remote":"103.242.190.99:62809","uuid":"4742c218-22f3-437a-afb1-bbfc93858d94","connectionId":48,"connectionCount":0}}
{"t":{"$date":"2021-09-07T14:42:32.577+00:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"Checkpointer","msg":"WiredTiger message","attr":{"message":"[1631025752:577252][445:0x7fc2bd773700], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 1491, snapshot max: 1491 snapshot count: 0, oldest timestamp: (0, 0) , meta checkpoint timestamp: (0, 0) base write gen: 1073601"}}
{"t":{"$date":"2021-09-07T14:43:32.583+00:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"Checkpointer","msg":"WiredTiger message","attr":{"message":"[1631025812:583826][445:0x7fc2bd773700], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 1492, snapshot max: 1492 snapshot count: 0, oldest timestamp: (0, 0) , meta checkpoint timestamp: (0, 0) base write gen: 1073601"}}
{"t":{"$date":"2021-09-07T14:44:20.706+00:00"},"s":"I",  "c":"QUERY",    "id":20528,   "ctx":"LogicalSessionCacheRefresh","msg":"Killing cursor as part of killing session(s)","attr":{"cursorId":6520707912476550687}}
{"t":{"$date":"2021-09-07T14:44:32.592+00:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"Checkpointer","msg":"WiredTiger message","attr":{"message":"[1631025872:592457][445:0x7fc2bd773700], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 1494, snapshot max: 1494 snapshot count: 0, oldest timestamp: (0, 0) , meta checkpoint timestamp: (0, 0) base write gen: 1073601"}}

steevej · 2021-09-07T14:55:03.463Z

I do not think that batchSize does what you expect to do.

See

mongodb.com

cursor.batchSize() — MongoDB Manual

You might want to look at

mongodb.com

$limit (aggregation) — MongoDB Manual

As a general comment you probably do not want to call MongoClients.create() at every query.

Same test now with the JS code.

khat33b · 2021-09-07T15:02:57.884Z

@steevej Yes, I wanted limit not batchSize, thanks. I ran in JS with hardcoded values without any match condition and got the result in 1223ms.

async PerpetualInventory(_, { batchSize }) {
	let res = [];
	try {
	  await client.connect();
	  const db = client.db('bird');

	  // Get the collection
	  const col = db.collection('inventory');
	  const startTime = new Date();
	  res = await col.aggregate([
	    {
	      $project: {
	        upc: 1,
	        inventory_name: 1,
	        street_date: 1,
	        format: 1,
	        sub_studio: 1,
	        us_base: 1,
	        us_srp: 1,
	        disc_num: 1,
	        modified_date: 1,
	        qoh: { $cond: [ {$and : [ { $gte: [ "$modified_date", dateFrom] }, { $lte: [ "$modified_date", dateTo] } ] }, "$qoh", 0 ] },
	      }
	    }
	  ]).limit(batchSize || 500).toArray();
	  const endTime = new Date();
	  const timeDiff = endTime - startTime;
	  console.log(timeDiff);
	} catch(err) {
	  console.log(err.stack);
	}
	return res;
}

khat33b · 2021-09-07T15:20:34.826Z

The mongod logs for the JS aggregation:

{"t":{"$date":"2021-09-07T14:59:47.724+00:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"103.242.190.99:56984","uuid":"0ed30111-95e5-4db4-9a7a-f789aee607ae","connectionId":51,"connectionCount":1}}
{"t":{"$date":"2021-09-07T14:59:47.730+00:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn51","msg":"client metadata","attr":{"remote":"103.242.190.99:56984","client":"conn51","doc":{"driver":{"name":"nodejs","version":"3.6.5"},"os":{"type":"Windows_NT","name":"win32","architecture":"x64","version":"10.0.19043"},"platform":"'Node.js v14.16.0, LE (legacy)"}}}
{"t":{"$date":"2021-09-07T14:59:47.986+00:00"},"s":"I",  "c":"ACCESS",   "id":20250,   "ctx":"conn51","msg":"Authentication succeeded","attr":{"mechanism":"SCRAM-SHA-256","speculative":true,"principalName":"jtvAdmin","authenticationDatabase":"admin","remote":"103.242.190.99:56984","extraInfo":{}}}
{"t":{"$date":"2021-09-07T15:00:07.637+00:00"},"s":"I",  "c":"NETWORK",  "id":22944,   "ctx":"conn51","msg":"Connection ended","attr":{"remote":"103.242.190.99:56984","uuid":"0ed30111-95e5-4db4-9a7a-f789aee607ae","connectionId":51,"connectionCount":0}}
{"t":{"$date":"2021-09-07T15:00:11.219+00:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"103.242.190.99:57008","uuid":"dd3a7536-9515-4f31-9b1b-2aa30e131d33","connectionId":52,"connectionCount":1}}
{"t":{"$date":"2021-09-07T15:00:11.226+00:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn52","msg":"client metadata","attr":{"remote":"103.242.190.99:57008","client":"conn52","doc":{"driver":{"name":"nodejs","version":"3.6.5"},"os":{"type":"Windows_NT","name":"win32","architecture":"x64","version":"10.0.19043"},"platform":"'Node.js v14.16.0, LE (legacy)"}}}
{"t":{"$date":"2021-09-07T15:00:11.489+00:00"},"s":"I",  "c":"ACCESS",   "id":20250,   "ctx":"conn52","msg":"Authentication succeeded","attr":{"mechanism":"SCRAM-SHA-256","speculative":true,"principalName":"jtvAdmin","authenticationDatabase":"admin","remote":"103.242.190.99:57008","extraInfo":{}}}
{"t":{"$date":"2021-09-07T15:00:32.744+00:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"Checkpointer","msg":"WiredTiger message","attr":{"message":"[1631026832:744247][445:0x7fc2bd773700], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 1513, snapshot max: 1513 snapshot count: 0, oldest timestamp: (0, 0) , meta checkpoint timestamp: (0, 0) base write gen: 1073601"}}

steevej · 2021-09-09T17:26:00.609Z

In java, you hard-code batchSize(5) while in JS you do a limit() so it is still not the same logic. You potentially return a lot more documents in the Java version. A batchSize(5) is really bad if you a lot of documents because it involves overhead at every 5 documents returned. A higher batchSize() is better. The best is to not change it.

Before redoing the test make, modify the code to print the size of the result set. Also print the first and last document to make sure we get the same result.

khat33b · 2021-09-14T10:18:15.263Z

It’s fixed. the problem was the batchSize itself. Removing it got my queries running quickly. Thank you @steevej for helping me with this. I was using batchSize when I should have been using limit. The variable in JS was batchSize for limits so I used the same in Java and that was what caused the problem.

system · 2021-09-19T10:18:30.261Z

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