Salesforce

How to identify and debug inefficient dynamic queries in ABL?

Printable View
« Go Back

Information

 
TitleHow to identify and debug inefficient dynamic queries in ABL?
URL NameHow-to-identify-and-debug-inefficient-dynamic-queries-in-ABL
Article Number000119092
EnvironmentProduct: OpenEdge
Version: 11.x, 12.x
OS: All supported platforms
Question/Problem Description
How to identify and debug inefficient dynamic queries in ABL?

Are there any debugging facilities available to help determine when dynamic queries are inefficient in terms of poor index bracketing and perhaps reading many more records (i.e. full table scan) than is necessary.  
 
Steps to Reproduce
Clarifying Information
Error Message
Defect Number
Enhancement Number
Cause
Resolution
Due to the nature of dynamic queries it isn't possible to review dynamic queries from a static code review, XREF listings or debug listings.  The only available ways to get dynamic query information are at runtime, and as follows:

1.  Use -clientlogging with the -logentrytype QRYINFO. 
  • The drawback with this method is that it needs to be configured at session start, so cannot be used in a session currently experiencing a problem. 
  • e.g. prowin32.exe -p .\progs\Dynamic-query-prepare.p -clientlog mylog.lg -logginglevel 2 -logentrytypes DB.Connects,4GLMessages,4GLTrace,QryInfo:4
  • This would create logging similar to:
[18/03/27@16:02:38.147+0100] P-009120 T-018000 1 4GL -- Log entry types activated: DB.Connects,4GLMessages,4GLTrace,QryInfo:4
[18/03/27@16:02:40.220+0100] P-009120 T-018000 2 4GL QRYINFO Query Plan: .\progs\Dynamic-query-prepare.p line 44
[18/03/27@16:02:40.220+0100] P-009120 T-018000 2 4GL QRYINFO QueryId: 2405630670928
[18/03/27@16:02:40.220+0100] P-009120 T-018000 2 4GL QRYINFO Query Handle: 1000
[18/03/27@16:02:40.220+0100] P-009120 T-018000 2 4GL QRYINFO Type: Dynamically Opened Query
[18/03/27@16:02:40.220+0100] P-009120 T-018000 2 4GL QRYINFO PREPARE-STRING: for each ttEmp where tcEmpName EQ "Mike~{Smith" 
[18/03/27@16:02:40.220+0100] P-009120 T-018000 2 4GL QRYINFO Prepared at Runtime
[18/03/27@16:02:40.220+0100] P-009120 T-018000 2 4GL QRYINFO Client Sort: N 
[18/03/27@16:02:40.220+0100] P-009120 T-018000 2 4GL QRYINFO Scrolling: Y
[18/03/27@16:02:40.220+0100] P-009120 T-018000 2 4GL QRYINFO Table: <TT>.ttEmp
[18/03/27@16:02:40.220+0100] P-009120 T-018000 2 4GL QRYINFO Indexes: idxEmpName
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO Query Statistics: .\progs\Dynamic-query-prepare.p line 56
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO QueryId: 2405630670928
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO Query Handle: 1000
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO Times prepared: 1
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO Time to prepare (ms): 0
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO DB Blocks accessed to prepare:
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO <TT> : 0
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO Times opened: 1
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO Used REPOSITION: N
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO DB Blocks accessed:
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO <TT> : 2
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO DB Reads:
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO Table: <TT>.ttEmp : UNAVAILABLE
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO Index: ttEmp.idxEmpName : UNAVAILABLE
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO <TT>.ttEmp Table:
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO 4GL Records: 1
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO Records from server: 1
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO Useful: 1
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO Failed: 0
[18/03/27@16:02:40.230+0100] P-009120 T-018000 2 4GL QRYINFO Select By Client: N

2.  Generate the same logging as -clientlog but using the LOG-MANAGER system handle.
  • The drawback of this method is that this requires predetermined code changes.  The logging is switched on and off by statements compiled into the code.
  • LOG-MANAGER:LOG-ENTRY-TYPES = "QryInfo:3"
3.  Use the INDEX-INFORMATION attribute of the query handle.
  • This option also needs code changes to implement.  
DEFINE VARIABLE hQuery AS HANDLE  NO-UNDO.
DEFINE VARIABLE ix     AS INTEGER NO-UNDO.
DEFINE VARIABLE jx     AS INTEGER NO-UNDO.

DEFINE QUERY q FOR Customer, Order, OrderLine SCROLLING.

hQuery = QUERY q:HANDLE.
hQuery:QUERY-PREPARE("FOR EACH Customer WHERE Customer.CustNum < 3,
EACH Order OF Customer, EACH OrderLine").
hQuery:QUERY-OPEN.

MESSAGE "prepare string is" hQuery:PREPARE-STRING VIEW-AS ALERT-BOX.

REPEAT ix = 1 TO hQuery:NUM-BUFFERS:
    jx = LOOKUP("WHOLE-INDEX", hQuery:INDEX-INFORMATION(ix)).
    MESSAGE hQuery:INDEX-INFORMATION(ix) VIEW-AS ALERT-BOX. 
    IF jx > 0 THEN
        MESSAGE "inefficient index" SKIP ENTRY(jx + 1, hQuery:INDEX-INFORMATION(ix)) SKIP(1)
            hQuery:INDEX-INFORMATION(ix) VIEW-AS ALERT-BOX. 
    ELSE 
        MESSAGE "bracketed index use of" SKIP hQuery:INDEX-INFORMATION(ix) SKIP(1)
            hQuery:INDEX-INFORMATION(ix) VIEW-AS ALERT-BOX.
END.
 
4.  Database Query table and index usage information can also be monitored using the _tablestat, _indexstat, _usertablestat and _userindexstat VST's.  
 
Workaround
Notes
References to Other Documentation:
OpenEdge Development: Debugging and Troubleshooting Guide, Chapter 5: "Logging in OpenEdge"
OpenEdge Development: Debugging and Troubleshooting Guide, Chapter 6: "Log Entry Types Detail"
OpenEdge Development: Debugging and Troubleshooting Guide, Chapter 7: "Other Diagnostics Resources"
OpenEdge Development: ABL Reference, "INDEX-INFORMATION attribute"
OpenEdge Deployment: Startup Command and Parameter Reference, Chapter 4: "Startup Parameter Descriptions"
OpenEdge Data Management: Database Administration, Chapter 22: "Database Startup Parameters"

Progress Article(s):
 How to turn on 4GL tracing within WebSpeed, AppServer and the 4GL Client?
Tracing Operations Per Table: VST's _tablestat _indexstat
 How to dectect when a widget has moved?
 
Keyword Phrase
Last Modified Date9/15/2020 8:45 PM
Powered by