Query is not killed when it is stopped

Markus Halttunen shared this question 13 days ago
Answered

I reported this issue https://mongobooster.useresponse.com/topic/allow-identifying-a-long-running-or-stuck-query-and-killing-it# two years ago, but the problem is still there.


Right now, I'm using version 6.1.8 of NoSqlBooster for MongoDB against MongoDB 4.0.9. Here are the steps to reproduce:

1. Run a query against a collection that has tens of millions of large entries. Make sure your query doesn't hit an index.

2. In another tab, run the currentOpActiveAndRunningLongerThan3Secs template to confirm that your query is visible

3. Stop the original query in the first tab

4. In the second tab, run the currentOpActiveAndRunningLongerThan3Secs again to confirm that the query is still there

5. Run db.killOp() using the operationId you got at 4

6. Run the currentOpActiveAndRunningLongerThan3Secs one more time to confirm that the query is gone


What should happen: In step 4 you should no longer see the query. You stopped it in NoSqlBooser so the query should have been killed.


What happens instead: In step 4 you still see the query and you have to kill it manually.


Are you 100% sure you can't reproduce this issue? Unfortunately, I can't give you access to our MongoDB but please tell me what kind of logging I can enable for you to understand in the logs what is going wrong?


Please advice, I really want to get this fixed.

Comments (1)

photo
1

Please take a look at your MongoDB Server's log file to check whether the command (killOp) has been called. Please note, even if the command is called and OK is returned, it does not mean that the long query has been killed. According to MongoDB 's Doc, killOp reports success if it succeeded in marking the specified operation for termination. Operations may not actually be terminated until they reach an appropriate interruption point. Use $currentOp or db.currentOp() to confirm the target operation was terminated. https://docs.mongodb.com/manual/reference/command/killOp/index.html#example

After you press the stop button, NoSQLBooster will call db.killOp(). But MongoDB's killOp doesn't take effect immediately. if you call db.currentOp, you will find that the flag bit of killPending has flagged. currentOp.killPending Returns true if the operation is currently flagged for termination. When the operation encounters its next safe termination point, the operation will terminate.

photo
1

I checked the MongoDB Server's logs. The killOp is NOT logged when I stop the query in NoSQLBooster. When I executed the killOp manually, I do see it in the logs and the query is immediately killed.

photo
1

Please take a look at this recording to see what happens: https://www.dropbox.com/s/ugikcqlkojc8ob8/MongoBoosterStopQuery1.mov?dl=0


If you want to see a more extensive recording to prove that it wasn't just about the delay between the killOp call and the actual termination, please see the following recording: https://www.dropbox.com/s/831xo8kuhfmt59q/MongoBoosterStopQuery2.mov?dl=0

(In the latter recording, please note how one of the queries just hangs and I have to stop it too. I'm seeing this quite often with MongoBooster. It may be a separate issue or possibly these two problems are connected)

photo
1

And again I repeat: Only see a line like "going to kill op: 118976666" when I kill the operation myself. NoSQLBooster does NOT send this command, and that is a fact.

photo
1

Thank you for your record.

We have worked out a new test build to resolve this issue, please download and give it a try.

MacOS: https://s3.mongobooster.com/download/releasesv6/nosqlbooster4mongo-6.2.1-beta.1.dmg

photo
1

Thank you for the quick response.


Unfortunately, there is something weird going on with that build. I am unable to connect to query the database. When I have connected, NoSQLBooster gives me the following error: "Cannot read property 'DBQuery' of undefined".


I have never seen this error with any other version of NoSQLBooster. Please advice.

photo
1

{

"message" : "Cannot read property 'DBQuery' of undefined",

"stack" : "TypeError: Cannot read property 'DBQuery' of undefined" +

"at /Applications/NoSQLBooster for MongoDB.app/Contents/Resources/app.asar/backend/mongoHandler.js:657:53" +

"at Array.forEach (<anonymous>)" +

"at MongoHandler.print (/Applications/NoSQLBooster for MongoDB.app/Contents/Resources/app.asar/backend/mongoHandler.js:653:18)" +

"at wrapper (/Applications/NoSQLBooster for MongoDB.app/Contents/Resources/app.asar/node_modules/lodash/lodash.js:4949:19)" +

"at Object.AKikL (evalmachine.<anonymous>:4:62059)" +

"at Mongo.<computed>.<computed> (evalmachine.<anonymous>:4:62137)" +

"at Mongo.obj.<computed> [as setSlaveOk] (/Applications/NoSQLBooster for MongoDB.app/Contents/Resources/app.asar/node_modules/mb-mquery/lib/mquery.js:3123:20)" +

"at MongoHandler.createInitSandbox (/Applications/NoSQLBooster for MongoDB.app/Contents/Resources/app.asar/backend/mongoHandler.js:1132:30)" +

"at MongoHandler.initRunningEnv (/Applications/NoSQLBooster for MongoDB.app/Contents/Resources/app.asar/backend/mongoHandler.js:966:31)" +

"at /Applications/NoSQLBooster for MongoDB.app/Contents/Resources/app.asar/backend/mongoHandler.js:734:22" +

"at tryBlock (/Applications/NoSQLBooster for MongoDB.app/Contents/Resources/app.asar/node_modules/asyncawait/src/async/fiberManager.js:39:33)" +

"at runInFiber (/Applications/NoSQLBooster for MongoDB.app/Contents/Resources/app.asar/node_modules/asyncawait/src/async/fiberManager.js:26:9)",

"_script" : "rs.status()"

}

photo
1

Is it simply that this database(secondary) cannot connect or any database cannot connect (including local and master node)?

Can you give me another recording?

photo
1

I confirm that I can connect to master using this version. However, I do not want to use master for these tests.

Here is a video of me connecting to a secondary: https://www.dropbox.com/s/x3huhxhsp4w1ljr/MongoBooster3.mov?dl=0

photo
1

We have worked out a new test build to resolve this issue, please download and give it a try.

MacOS: https://s3.mongobooster.com/download/releasesv6/nosqlbooster4mongo-6.2.1-beta.2.dmg

Because the next two days are weekend, if this build still has problems, we can only study this question next week, if possible, please test it on the master node or another test database.

photo
1

Thank you for the new build. This build fixed the "Cannot read property 'DBQuery' of undefined" but unfortunately it works identically to the current released build when it comes to killing the operation when the query is stopped. I could provide you with a video, but it would look identical to the original video I sent to you.

I checked the logs and there are no log entries when I stop the query. Can you tell me what information I can provide to you or can you please make another build that includes much more logging so you can get to the bottom of this. I am happy to share with you e.g. anything written in the "Log Window".

photo
1

Could you show me the execution result of the command "db.currentOp()" (json text) after clicking "stop" button?

photo
1

{
	"host" : "ip-172-31-31-26.mongo:27017",
	"desc" : "conn2926551",
	"connectionId" : 2926551,
	"client" : "172.31.42.99:40084",
	"appName" : "NoSQLBoosterV6.2.1-beta.2_151935.514",
	"clientMetadata" : {
		"driver" : {
			"name" : "nodejs",
			"version" : "3.6.3"
		},
		"os" : {
			"type" : "Darwin",
			"name" : "darwin",
			"architecture" : "x64",
			"version" : "19.6.0"
		},
		"platform" : "'Node.js v12.8.1, LE (legacy)",
		"application" : {
			"name" : "NoSQLBoosterV6.2.1-beta.2_151935.514"
		}
	},
	"active" : true,
	"currentOpTime" : "2020-11-16T07:49:27.394+0000",
	"opid" : 844772451,
	"secs_running" : 51,
	"microsecs_running" : 51235195,
	"op" : "query",
	"ns" : "empires.players",
	"command" : {
		"find" : "players",
		"filter" : {
			"Language" : "Foobar"
		},
		"sort" : {
			"_id" : -1
		},
		"projection" : {
			
		},
		"limit" : 100,
		"returnKey" : false,
		"showRecordId" : false,
		"$clusterTime" : {
			"clusterTime" : Timestamp(1605512915, 2080),
			"signature" : {
				"hash" : BinData(0,"FhdFqVm9+p/vH8gz85B45uXHgnQ="),
				"keyId" : NumberLong("6844155146386017270")
			}
		},
		"$db" : "empires",
		"$readPreference" : {
			"mode" : "secondary"
		}
	},
	"planSummary" : "IXSCAN { _id: 1 }",
	"numYields" : 2583,
	"locks" : {
		"Global" : "r",
		"Database" : "r",
		"Collection" : "r"
	},
	"waitingForLock" : false,
	"lockStats" : {
		"Global" : {
			"acquireCount" : {
				"r" : 2584
			}
		},
		"Database" : {
			"acquireCount" : {
				"r" : 2584
			}
		},
		"Collection" : {
			"acquireCount" : {
				"r" : 2584
			}
		}
	}
}

photo
1

Thank you for your patience.

This problem is actually a bit difficult. MongoDB only provides a db.currentOp () method, but there is no good way to find an opid that matches the script executed on the current tab sheet of NoSQLBooster. NoSQLBooster allows multiple queries to be executed at the same time, and we cannot mistakenly kill other scripts that are running.

We have worked out a new test build to try to resolve this issue, please download and give it a try.

MacOS: https://s3.mongobooster.com/download/releasesv6/nosqlbooster4mongo-6.2.1-beta.3.dmg

If it still does not work. Please enable developer mode to collect information for diagnostics.

1. cd /Applications/NoSQLBooster for MongoDB.app/Contents/MacOS


2. NODE_ENV=dev ./NoSQLBooster\ for\ MongoDB

Save the logs: Right-click at any place in the console content, and choose "Save as..."

/4314b479f2fb3d39327e744f0f8e13c8

photo
1

Thank you for the new build. Unfortunately, it did not do anything different.

These logs are not too sensitive, but is there a way for me to share them with you non-publicly? Besides, how do I attach files here?

photo
1

I decided to send an email.

photo