SQLserver SELECT query taking over 4s, please advise on howto diagnose and identify causes

Francisco_Caro · February 1, 2024, 9:30pm

Hi, just learning the ropes here in the Ignition ecosystem. Lots of interesting tools, kinda lost on howto go about diagnosing issues.

In a nutshell --- using the Ignition Gateway > Status > Connections > Databases > clicking on the database with the most connections & Queries/sec --> leads to some very interesting information.

The table describing "Longest Recent Queries" has a duration of typically > 1s sometimes even 4s.

The query structure is weird

SELECT a."id",a."tagpath",a."datatype",a."scid",a."querymode",a."created",a."retired" FROM sqlth_te a,sqlth_scinfo b WHERE (a."tagpath"=? OR a."tagpath"=? OR a."tagpath"=? OR a."tagpath"=? OR a."tagpath"=? OR a."tagpath"=? OR a."tagpath"=? OR a."tagpath"=? OR a."tagpath"=? OR a."tagpath"=? OR a."tagpath"=? OR a."tagpath"=?) AND (a."scid"=0 OR a."scid"=b."id" AND (b."drvid"=? OR b."drvid"=?)) ORDER BY a."retired" DESC

Plus I am new to the system and the legacy project it involves. So hence I ask on these forums for some guidance in howto further dig into this issue.

My hope is that from this SQL query --> identify the logs that further describe the events leading up to it --> identify the script/component triggering this query to trigger ---> maybe optimize the query, or evaluate if an alternative solution can be applied.

Since this is all new to me, at least we were able to identify this very valuable table "Longest Recent Queries" .

Any help would be greatly appreciated.

MMaynard · February 1, 2024, 9:40pm

That looks like a very large historical or real time trend on a vision window somewhere.

Transistor · February 1, 2024, 9:41pm

A tiny bit of help: Let's make it readable.

SELECT 
  a."id",
  a."tagpath",
  a."datatype",
  a."scid",
  a."querymode",
  a."created",
  a."retired" 
FROM 
    sqlth_te a,
    sqlth_scinfo b 
WHERE (a."tagpath" = ? 
    OR a."tagpath" = ?  
    OR a."tagpath" = ? 
    OR a."tagpath" = ? 
    OR a."tagpath" = ? 
    OR a."tagpath" = ? 
    OR a."tagpath" = ? 
    OR a."tagpath" = ? 
    OR a."tagpath" = ? 
    OR a."tagpath" = ? 
    OR a."tagpath" = ? 
    OR a."tagpath" = ?
  ) 
  AND (
    a."scid" = 0 
    OR a."scid" = b."id" 
    AND (b."drvid" = ? OR b."drvid" = ?)
  ) 
ORDER BY a."retired" DESC

Tip: put spaces both sides of the equals operator same as you would writing it out in English. Add a space after a comma, as in English.

Matrix_Engineering · February 1, 2024, 9:49pm

Apologies in advance for my useless contribution to this thread.

People that , put a space before , and after the comma , in emails etc . , really peev me =\

Francisco_Caro · February 1, 2024, 9:57pm

yes, no doubt about it. Some tag history data being collected, and some component is doing the unfortunate task of fetching it. Which component? Which script? Which property? hmmmm ... only the previous Engineer knows.

I'm on the hunt for more logs, something suspicious is happening around that database connection.

Francisco_Caro · February 1, 2024, 10:00pm

thank you, that does show in a much nicer form, just how weird that query is structured out to be. Could it be the only problem with the project, I hope so, but my luck would be the opposite. Hahaha, my hunt for the bottleneck is just getting started.

Any ideas on howto go from the Query --> to the logs ---> to help identifying the Vision app / component / script?

One things for sure, I did not write that SQL query. Hahaha

JordanCClark · February 1, 2024, 10:02pm

This looks to be a home made query. Have you tried the Find/Replace tool? I'd narrow the search term to something like a."scid".

Francisco_Caro · February 1, 2024, 10:24pm

Thanks JordanCClark. Forgot about that tool.

I am giving it a try with no luck though...

But certainly gonna try different keyword combinations. Maybe something pops up along the way.

MMaynard · February 2, 2024, 12:53pm

More than likely a chart control.
You can search for Easy or if you are using the AdHoc trending template, search for AdHoc and choose all windows in the search tool.

Francisco_Caro · February 2, 2024, 1:18pm

Thanks MMaynard,

that is super cool... searching for keyword "easy" is giving me a small list of scripts to inspect.

And what a cool tool, just dbl clicking takes me to the exact component/location/script editor. Nice. The hunt continues

pascal.fragnoud · February 2, 2024, 1:46pm

The presence of "?" in the query suggests it is not a named query. I'd search for prep queries, which use this syntax.

MMaynard · February 2, 2024, 2:53pm

Every historical query will show up like that.
It is a sore point with me just for the reasons of this thread.

pturmel · February 2, 2024, 3:24pm

But how could they not? Everything done efficiently in JDBC is a "Prep" query. Even Named Queries get converted to JDBC "Prep" queries.

PGriffith · February 2, 2024, 3:33pm

The Gateway.Database.Selects logger will show every query Ignition is firing, and I believe it logs every parameter as well, which should help track it down. Beware of serious noise in the logs, though - when I say every, I mean every.

Francisco_Caro · February 2, 2024, 3:51pm

Well that is interesting, just not sure if I am doing that search correctly.

Now there is mention of a slow query in that gateway.database.selects logging info, and theres a "magnifying glass" icon that provides further information as to which user/project/db executed this query.

So thats cool to see happening.

Anywhere else I can browse/filter for the gateway.database.selects logs?

pturmel · February 2, 2024, 3:54pm

You have to change that logger's level to DEBUG or TRACE to get more detail. Use the gear icon on that page. (But watch out--it'll fill your logs.)

Francisco_Caro · February 2, 2024, 4:25pm

Thats interesting, ok so by changing that now ... does that mean that the logs visualized on Status>Diagnostics > Logs are going to show me the older logs in more "Debug" detail? Or only from now onwards, since setting "gateway.database.selects" logs to "DEBUG" mode, will that level of detail be available.

Well. I just now changed it, so I guess the Ignition Gateway will be answering my question shortly.

pturmel · February 2, 2024, 4:47pm

This.

Francisco_Caro · February 2, 2024, 5:18pm

placing "gateway.database.selects" in TRACE mode, boy-o-boy --- did that open the flood gates.

Allowed it to gather logs for 15mins. And then changed it back to "INFO" mode. Downloaded the sqlite log file (opened in DBeaver). Otherwise as you mentioned earlier, space allocated for logs on the server is gonna explode when I come back to the office on monday. hahaha.

Although the same query did not popup, something similar did. And with the help of the "magnifying glass icon", I was able to find a hint of which project such a query is part of. I assumed it was part of the Vision side of the project, but there in the logs it confirms to be part of the Perspective side of the project. With that I have a few suspects (aka team-members) I can interrogate, since some seniors are working on the Perspective side.

So in brief summary ---
on the LOGS side ( a way to filter in TRACE mode, the specific logger associated with SELECT queries )
On the Ignition Designer side ( a tool to FIND&REPLACE and try keyword combinations that help me find scripts/components/properties related to the SQL query).

I haven't gotten my A-HA moment yet, but I am getting closer.
Thanks to everyone that has helped and answered my rather vague forum query.

PGriffith · February 2, 2024, 5:26pm

Consider Kindling for a nicer dedicated view of Ignition SQLite files