runNamedQuery running slowly

Ignition
#1

In investigating some performance issues in my project, I found that my named queries, which I just started using/converting to, were running very slowly. If I have a client window open for my project, the difference between runQuery and runNamedQuery is very large. If I do not have a client window open for my project, the difference is still significant, but much less noticeable. Please see my test below:

# start test code
totalNamedQueryMs = 0
totalQueryMs = 0

for testNumber in range(10):
	print('test%d' % testNumber)
	start = system.date.now()
	for i in range(100):
		test = system.db.runNamedQuery('select1', {})
	msElapsed = system.date.millisBetween(start, system.date.now())
	print('  runNamedQuery took %d ms' % msElapsed)
	totalNamedQueryMs += msElapsed
	
	start = system.date.now()
	for i in range(100):
		test = system.db.runQuery('''select 1''')
	msElapsed = system.date.millisBetween(start, system.date.now())
	print('  runQuery took %d ms' % msElapsed)
	totalQueryMs += msElapsed
	
print('avg seconds to run 100 "select 1" using runNamedQuery: %2f' % (totalNamedQueryMs / 10000.0))
print('avg seconds to run 100 "select 1" using runQuery:      %2f' % (totalQueryMs      / 10000.0))

Results while client window is open (and running normal queries, currently ~30/second)

test0
  runNamedQuery took 28771 ms
  runQuery took 103 ms
test1
  runNamedQuery took 28051 ms
  runQuery took 102 ms
test2
  runNamedQuery took 29323 ms
  runQuery took 120 ms
test3
  runNamedQuery took 29915 ms
  runQuery took 95 ms
test4
  runNamedQuery took 31524 ms
  runQuery took 109 ms
test5
  runNamedQuery took 27637 ms
  runQuery took 105 ms
test6
  runNamedQuery took 27647 ms
  runQuery took 89 ms
test7
  runNamedQuery took 28750 ms
  runQuery took 103 ms
test8
  runNamedQuery took 27985 ms
  runQuery took 92 ms
test9
  runNamedQuery took 29025 ms
  runQuery took 93 ms
avg seconds to run 100 "select 1" using runNamedQuery: 28.862800
avg seconds to run 100 "select 1" using runQuery:      0.101100

Results while client window is not open:

test0
  runNamedQuery took 550 ms
  runQuery took 74 ms
test1
  runNamedQuery took 561 ms
  runQuery took 71 ms
test2
  runNamedQuery took 565 ms
  runQuery took 73 ms
test3
  runNamedQuery took 531 ms
  runQuery took 74 ms
test4
  runNamedQuery took 547 ms
  runQuery took 70 ms
test5
  runNamedQuery took 535 ms
  runQuery took 72 ms
test6
  runNamedQuery took 556 ms
  runQuery took 73 ms
test7
  runNamedQuery took 535 ms
  runQuery took 75 ms
test8
  runNamedQuery took 536 ms
  runQuery took 73 ms
test9
  runNamedQuery took 542 ms
  runQuery took 70 ms
avg seconds to run 100 "select 1" using runNamedQuery: 0.545800
avg seconds to run 100 "select 1" using runQuery:      0.072500
1 Like
#2

Same results using the H2 database instead of MSSQL. Similar results run on my test Linux gateway.

#3

Wow. I can’t say I’ve seen that in my testing, but I’ll definitely take a look at it. :flushed:

1 Like
#4

Okay, I’ve been able to run some tests, and have come up with a few things.

When running the query in the Designer, I’m seeing about the same absolute difference in time between the system.db.runQuery and the named query – about 5ms per query. Doing some experimenting in the code, a small part of that difference is the fact than named queries always use prepared statements even when there are no parameters, and the rest of the difference is that named queries are a resource and the Designer needs to look at all the named query resources it knows about to find the right one.

I’m not 100% sure what you were seeing when you said you had a Client window open. I got the same Designer results whether or not I had a Client window open, but I did get significantly slower results when running the query from the Client. Not as large as yours, but still bigger than I expected. Again, after experimenting, I can trace it to two things. Again, we have the prepared statement issue, which is very small. The biggest factor was that the gateway (where that client query is actually run) needs to first find the correct project in the internal database and then find the correct query resource. I’d guess that you probably have a lot more resources than I do in my test system. so finding the correct resource in the internal db is much slower. Also if you’ve got a lot going on in your system, the read from the internal db may be temporarily blocked, again making this search slow.

I’m not surprised the database used made no difference. Once the named query has been found and the prepared statement has been created, the time for the query itself should be very similar between legacy and named queries, assuming you aren’t using a cached result in the named query.

All that said, I have some ideas about revamping our existing caching a bit to speed this up. The cut off for 7.9.7 just passed, but I should have no trouble getting this into 7.9.8.

#5

Thanks for the quick response! I’ve been out of commission for the past few days myself.

I wonder if there could be some sort of mechanism like a function like system.db.lookupNamedQuery(queryName) that would return a reference to the query. For use in a script, you could call my theoretical function before a for loop, then in the for loop, reference the Named Query by some sort of identifier that makes lookups faster.

Not sure if this would work within how Ignition works on the backend, just a thought.

#6

Good idea, but definitely wouldn’t work on the back end.

You might try using the caching option on your named queries, though. When that’s turned on, the results are cached based on the text of the query and the values of the parameters you send in. That eliminates trips to the database when re-running the same query. May not help a for-loop much, but it’s a huge help when you have a hundred clients doing the same query.

We’re also planning on adding batching to named queries, but that probably won’t be for a while yet.

#7

Sounds like batching would be very useful.

#8

I’ll also chime in and say I’m running into the same slowness issues with named queries.

To test out the difference I took one of our functions, which takes the Tag Tree and checks all of the UDT’s of a certain type to make sure they exist in another database.
Because of the number of checks it does the function runs 6 different named queries for each UDT that is found.

For 134 tags it took about 183 seconds to run the function using named Queries.
The same 134 tags took 26 seconds using Prep and PrepScalar Queries.

for now we’re going back thru and converting anything that is time sensitive to the “Old” method of having the query in the Script Library.

#9

Good news, all. I’ve completed the revamp of named queries, and it will be in Ignition 7.9.8, which is going to QA in a couple of weeks.

Here’s the test results:

avg ms to run 100 "select 1" using runQuery:      194```

```avg ms to run 100 "select 1" using runNamedQuery: 172
avg ms to run 100 "select 1" using runQuery:      193```

```avg ms to run 100 "select 1" using runNamedQuery: 159
avg ms to run 100 "select 1" using runQuery:      190```

These were **not** using caching on the queries. Note that the absolute times are not important -- what we're looking at here is the relative difference, which means that named queries have gone from being slower to being the same or faster.
3 Likes
#10

Wow, thanks so much Kathy for the quick turnaround! I look forward to converting all my queries to named queries with confidence. Happy New Year!

1 Like
#11

I’m running ignition version 7.9.10 and I’m seeing a huge difference between runQuery and runNamedQuery when executed on the gateway. I ran the same test posted by @fourmajor and got the following results:

avg seconds to run 100 "select 1" using runQuery: 0.120200
avg seconds to run 100 "select 1" using runNamedQuery: 137.943400