Tip:  Troubleshooting slow running application via database

Summary

SLOWSQL log message from Service Center and Slow Call from Lifetime dashboard analytics alert us of a performance problem on our application but more information is required specifically relating to database activity.  

You can also use this guide to troubleshoot applications that are hanging or unresponsive and are suspected to be database related issues.

In this post, I will go over how to extract specific information from the database when dealing with these types of log information. 


1. ) Installation Prerequisite

Before we begin, we first need to enable some platform settings. For this, we will need to install the Factory Configuration forge component.  

Once installed, open it on the browser and navigate to the Platform Configurations tab.

Scroll down and find the setting Add Query Origin to Generated SQL then make sure it is ticked and save your changes.


Info - Query Origin to Generated SQL

After the changes have been saved, applications need to be published again since this feature is applied at the compilation level. SQL generated by your OutSystems application will now include a comment with the location of the SQL in your application code.  This can be handy to relate the information from the database with the logs from Service Center or Lifetime Analytics dashboard.

Here are examples of what additional information will appear with the SQL statements.

/* Query.VendorScreen.Vendor_Search.Preparation.Vendor.List */ 

SELECT [ENVENDOR].[ID] o0, [ENVENDOR].[NAME] o1, [ENVENDOR].[TYPE] o2

FROM [OUTSYSTEMS].dbo.[OSUSR_F66_VENDOR] [VENDOR]


This can be broken down into different sections


MODULE

UI FLOW

SCREEN

QUERY

eSpace(Independent Modules)     

VendorScreen    

Vendor_Search    

Preparation.Vendor.List



2. ) Setting up Database connectivity

Setup connectivity to the database server (PaaS customers)

Please skip this step if you already have connectivity to the database server. 

OutSystems allows you to connect in two different ways:

  • Connect to the database server from any IP address of your private network. You must establish this connection through VPN or AWS Transit Gateway.

  • Connect to the database server from a set of public static IP addresses, allowlisted on the OutSystems side.

 

3.) Setting up Database Login


Create a database user login to the database (PaaS customers)

Please skip this step if you already have user access to the database server. 

For temporary or permanent database users and more information, you can follow the process described in OutSystems’ public documentation.  


Create a database user login to the database (On-Prem customers)


Create or use an existing database login and enable the following settings:

For SQL Server

  • VIEW DATABASE STATE

  • VIEW SERVER STATE

  • SHOWPLAN

For Oracle:

  • SELECT ANY DICTIONARY



Checklist before proceeding to the next step

  1. Enable add query origin to SQL generated using Factory Configuration forge component

  2. Setup connectivity to the database server

  3. Setup database user




Matching application message with SQL statements generated by the application


Service Center General log SLOWSQL message would look something like this:


Module

Message

eSpace(Independent Modules)    

Query.VendorScreen.Vendor_Search.Preparation.Vendor.List took 10010 ms (Database: outsystems)



Work with an OutSystems developer to identify which screen or part of the application where the SLOWSQL is being generated from. 

As per example above, the Vendor web screen and fetching the list of the Vendor is the part of the application which has generated the SLOWSQL message.

From the database point of view, you can either debug the screen / application and run a trace in order to see the SQL statement being executed by the application.


/* Query.VendorScreen.Vendor_Search.Preparation.Vendor.List */ 

SELECT [ENVENDOR].[ID] o0, [ENVENDOR].[NAME] o1, [ENVENDOR].[TYPE] o2

FROM [OUTSYSTEMS].dbo.[OSUSR_F66_VENDOR] [VENDOR]


The SQL statement comment can be matched with the SLOWSQL message to help identify the correct query running on the server.


Debugging using open session / cached queries view


For the steps below you need to have access to the OutSystems Database. Please note that this will only capture what is currently running  and stored on the query cache.

To extract this information is by running queries via the database cache which we will go over them below.  Please note that these queries can be executed by temporary and permanent database users.

To use the query effectively, it needs to be executed while the suspect page or process is running at the same time to capture the SQL statement sessions currently running on the server. 

SQL statement is already parsed and a new column "Module_path" shows the query origin location.


SQL Server


SELECT top 100

CASE WHEN LEFT(LEFT(t.text,400), 3) = '/* ' THEN SUBSTRING(LEFT(t.text,400), 4, (CHARINDEX(' */',LEFT(t.text,400), 3)-3))

ELSE CASE WHEN LEFT(LEFT(t.text,400),2) = '(@' AND LEFT(t.text,400) like '(@%)/*%' THEN  SUBSTRING(LEFT(t.text,400), CHARINDEX('/* ',LEFT(t.text,400))+3, CHARINDEX('*/',LEFT(t.text,400))- CHARINDEX('/* ',LEFT(t.text,400))-3) END 

END as 'Module_Path',


t.[text] AS 'QueryText',

qp.query_plan AS 'QueryPlan',

CONVERT(DECIMAL(10,2), (total_worker_time+0.0)/(execution_count*1000))    AS 'CPUTime',

qs.last_logical_reads as 'IORead', 

qs.last_logical_writes as 'IOWrite',

qs.total_elapsed_time/1000 as TotDuration,

qs.execution_count AS 'ExecutionCount', 

last_execution_time 'ExecutionTime',

DB_NAME(t.[dbid]) AS 'DatabaseName',

cp.objtype as 'CacheType',

qs.sql_handle


FROM sys.dm_exec_query_stats AS qs WITH (NOLOCK)

CROSS APPLY sys.dm_exec_sql_text(plan_handle) AS t 

CROSS APPLY sys.dm_exec_query_plan(plan_handle) AS qp 

left JOIN sys.dm_exec_cached_plans as cp ON qs.plan_handle = cp.plan_handle


/*

-- specific text filter on sql statement

where t.text like '%VendorScreen%'

*/



Oracle


SELECT DISTINCT

CASE WHEN SUBSTR(SUBSTR(v.SQL_TEXT,1, 400), 1, 3) = '/* ' THEN SUBSTR(SUBSTR(v.SQL_TEXT,1, 400), 4, (INSTR(SUBSTR(v.SQL_TEXT,1, 400), ' */', 3)-3))

ELSE CASE WHEN SUBSTR(SUBSTR(v.SQL_TEXT,1, 400), 1,2) = '(@' AND SUBSTR(v.SQL_TEXT,1, 400) like '(@%)/*%' THEN  SUBSTR(SUBSTR(v.SQL_TEXT,1, 400), INSTR(SUBSTR(v.SQL_TEXT,1, 400), '/* ')+3, INSTR(SUBSTR(v.SQL_TEXT,1, 400), '*/')- INSTR(SUBSTR(v.SQL_TEXT,1, 400), '/* ')-3)

END END as module_path,

v.SQL_TEXT,

v.EXECUTIONS, 

v.CPU_TIME,

v.DISK_READS,

v.DIRECT_WRITES,

v.elapsed_time,

v.SQL_ID

FROM v$sql v 

WHERE to_date(v.FIRST_LOAD_TIME,'YYYY-MM-DD hh24:mi:ss')>ADD_MONTHS(trunc(sysdate,'DD'),-1) -- Query date criteria from yesterday

/*

-- specific text filter on sql statement

AND v.SQL_TEXT LIKE '%VendorScreen%'

*/

FETCH FIRST 100 ROWS ONLY  -- top 100


Another use case for this query is during an incident or outage that is currently happening. It will give you an ability to view what is currently running which is potentially blocking the processes on your application. This will enable you to collect a snapshot list of SQL statements which you can look into or cross check against the logs.

For more detailed information regarding debugging Outsystems application please read the Official Outsystems Documentation on our website.


Extending the query timeout

Sometimes we find too many log warnings due to the fact that the query was not given sufficient enough time to execute.  You can extend this by changing the values of the setting in the Factory Configuration.  This will help in refining and reducing the amount of log error messages.




Hope you find this information useful.

Regards

-Raynino


Cool stuff @Raynino 


Thanks for sharing it :)

Community GuidelinesBe kind and respectful, give credit to the original source of content, and search for duplicates before posting.