Skip to content

Commit

Permalink
IDEMPIERE-6123 Query in search window causing slowness and load spike…
Browse files Browse the repository at this point in the history 
…s in the database (FHCA-5356) (#2340)

* IDEMPIERE-6123 Query in search window causing slowness and load spikes in the database (FHCA-5356)

* - create SysConfig
- add Dialog when reaching max query records

* - minor fix comment
- add timeout management to MLookup query

* - Fix for the GridTable.Loader.Open issue

* - add SysConfig and Messages
- add showing error message when the number of records loaded in background exceed the allowed
- add timeout to GridTable.fillBuffer

---------

Co-authored-by: hengsin <hengsin@gmail.com>
  • Loading branch information
@CarlosRuiz-globalqss @hengsin
CarlosRuiz-globalqss and hengsin committed May 3, 2024
1 parent 8ed7823 commit 881e758
Show file tree
Hide file tree
Showing 10 changed files with 215 additions and 90 deletions.
22 changes: 22 additions & 0 deletions migration/iD11/oracle/202404302320_IDEMPIERE-6123.sql
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,22 @@
-- IDEMPIERE-6123 Query in search window causing slowness and load spikes in the database (FHCA-5356)
SELECT register_migration_script('202404302320_IDEMPIERE-6123.sql') FROM dual;

SET SQLBLANKLINES ON
SET DEFINE OFF

-- Apr 30, 2024, 11:20:08 PM CEST
INSERT INTO AD_SysConfig (AD_SysConfig_ID,AD_Client_ID,AD_Org_ID,Created,Updated,CreatedBy,UpdatedBy,IsActive,Name,Value,Description,EntityType,ConfigurationLevel,AD_SysConfig_UU) VALUES (200244,0,0,TO_TIMESTAMP('2024-04-30 23:20:08','YYYY-MM-DD HH24:MI:SS'),TO_TIMESTAMP('2024-04-30 23:20:08','YYYY-MM-DD HH24:MI:SS'),100,100,'Y','GRIDTABLE_INITIAL_COUNT_TIMEOUT_IN_SECONDS','1','Timeout for the initial count on windows','D','C','5fae1af7-74ca-41d8-bbd3-d506c6c23b6a')
;

-- Apr 30, 2024, 11:22:16 PM CEST
INSERT INTO AD_SysConfig (AD_SysConfig_ID,AD_Client_ID,AD_Org_ID,Created,Updated,CreatedBy,UpdatedBy,IsActive,Name,Value,Description,EntityType,ConfigurationLevel,AD_SysConfig_UU) VALUES (200245,0,0,TO_TIMESTAMP('2024-04-30 23:22:16','YYYY-MM-DD HH24:MI:SS'),TO_TIMESTAMP('2024-04-30 23:22:16','YYYY-MM-DD HH24:MI:SS'),100,100,'Y','GLOBAL_MAX_QUERY_RECORDS','100000','Maximum number of records allowed to search in a window, can be overriden per Role or Tab','D','C','840fb67c-4609-41f2-9e20-e0ea9d839065')
;

-- Apr 30, 2024, 11:23:28 PM CEST
UPDATE AD_Message SET MsgText='The query returned more records than allowed, consider adding more filters.',Updated=TO_TIMESTAMP('2024-04-30 23:23:28','YYYY-MM-DD HH24:MI:SS'),UpdatedBy=100 WHERE AD_Message_ID=852
;

-- Apr 30, 2024, 11:24:06 PM CEST
INSERT INTO AD_Message (MsgType,MsgText,AD_Client_ID,AD_Org_ID,IsActive,Created,CreatedBy,Updated,UpdatedBy,AD_Message_ID,Value,EntityType,AD_Message_UU) VALUES ('I','The initial count query timed out, loading records ...',0,0,'Y',TO_TIMESTAMP('2024-04-30 23:24:06','YYYY-MM-DD HH24:MI:SS'),100,TO_TIMESTAMP('2024-04-30 23:24:06','YYYY-MM-DD HH24:MI:SS'),100,200887,'CountQueryTimeoutLoadBackground','D','988292d7-175f-41c2-b560-43d62b8326a9')
;

19 changes: 19 additions & 0 deletions migration/iD11/postgresql/202404302320_IDEMPIERE-6123.sql
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,19 @@
-- IDEMPIERE-6123 Query in search window causing slowness and load spikes in the database (FHCA-5356)
SELECT register_migration_script('202404302320_IDEMPIERE-6123.sql') FROM dual;

-- Apr 30, 2024, 11:20:08 PM CEST
INSERT INTO AD_SysConfig (AD_SysConfig_ID,AD_Client_ID,AD_Org_ID,Created,Updated,CreatedBy,UpdatedBy,IsActive,Name,Value,Description,EntityType,ConfigurationLevel,AD_SysConfig_UU) VALUES (200244,0,0,TO_TIMESTAMP('2024-04-30 23:20:08','YYYY-MM-DD HH24:MI:SS'),TO_TIMESTAMP('2024-04-30 23:20:08','YYYY-MM-DD HH24:MI:SS'),100,100,'Y','GRIDTABLE_INITIAL_COUNT_TIMEOUT_IN_SECONDS','1','Timeout for the initial count on windows','D','C','5fae1af7-74ca-41d8-bbd3-d506c6c23b6a')
;

-- Apr 30, 2024, 11:22:16 PM CEST
INSERT INTO AD_SysConfig (AD_SysConfig_ID,AD_Client_ID,AD_Org_ID,Created,Updated,CreatedBy,UpdatedBy,IsActive,Name,Value,Description,EntityType,ConfigurationLevel,AD_SysConfig_UU) VALUES (200245,0,0,TO_TIMESTAMP('2024-04-30 23:22:16','YYYY-MM-DD HH24:MI:SS'),TO_TIMESTAMP('2024-04-30 23:22:16','YYYY-MM-DD HH24:MI:SS'),100,100,'Y','GLOBAL_MAX_QUERY_RECORDS','100000','Maximum number of records allowed to search in a window, can be overriden per Role or Tab','D','C','840fb67c-4609-41f2-9e20-e0ea9d839065')
;

-- Apr 30, 2024, 11:23:28 PM CEST
UPDATE AD_Message SET MsgText='The query returned more records than allowed, consider adding more filters.',Updated=TO_TIMESTAMP('2024-04-30 23:23:28','YYYY-MM-DD HH24:MI:SS'),UpdatedBy=100 WHERE AD_Message_ID=852
;

-- Apr 30, 2024, 11:24:06 PM CEST
INSERT INTO AD_Message (MsgType,MsgText,AD_Client_ID,AD_Org_ID,IsActive,Created,CreatedBy,Updated,UpdatedBy,AD_Message_ID,Value,EntityType,AD_Message_UU) VALUES ('I','The initial count query timed out, loading records ...',0,0,'Y',TO_TIMESTAMP('2024-04-30 23:24:06','YYYY-MM-DD HH24:MI:SS'),100,TO_TIMESTAMP('2024-04-30 23:24:06','YYYY-MM-DD HH24:MI:SS'),100,200887,'CountQueryTimeoutLoadBackground','D','988292d7-175f-41c2-b560-43d62b8326a9')
;

8 changes: 4 additions & 4 deletions org.adempiere.base/src/org/compiere/model/DataStatusEvent.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -257,10 +257,9 @@ public String getMessage()
retValue.append(m_currentRow+1);
// of
retValue.append("/");
if (m_allLoaded)
retValue.append(m_totalRows);
else
retValue.append(m_loadedRows).append("->").append(m_totalRows);
if (! m_allLoaded)
retValue.append(m_loadedRows).append("->");
retValue.append(m_totalRows);
//
return retValue.toString();
} // getMessage
Expand Down Expand Up @@ -358,6 +357,7 @@ public boolean isEqual(DataStatusEvent e) {
e.m_changedColumn == m_changedColumn &&
Util.equals(e.m_columnName, m_columnName) &&
e.m_currentRow == m_currentRow &&
e.m_loadedRows == m_loadedRows &&
e.isInitEdit == isInitEdit;
}

Expand Down
16 changes: 12 additions & 4 deletions org.adempiere.base/src/org/compiere/model/GridTab.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -235,6 +235,8 @@ public GridTab(GridTabVO vo, GridWindow w, boolean virtual)
public static final String CTX_IsLookupOnlySelection = "_TabInfo_IsLookupOnlySelection";
public static final String CTX_IsAllowAdvancedLookup = "_TabInfo_IsAllowAdvancedLookup";

public static final int DEFAULT_GLOBAL_MAX_QUERY_RECORDS = 100000;

/**
* Tab loader for Tabs > 0
*/
Expand Down Expand Up @@ -2557,20 +2559,23 @@ private int verifyRow (int targetRow)
}
// Row Count
int rows = getRowCount();
if (rows == 0)
if (rows == 0 && !m_mTable.isLoading())
{
log.fine("No Rows");
return -1;
}
if (newRow >= rows)
{
newRow = rows-1;
if (log.isLoggable(Level.FINE)) log.fine("Set to max Row: " + newRow);
if (!m_mTable.isLoading())
{
newRow = rows-1;
if (log.isLoggable(Level.FINE)) log.fine("Set to max Row: " + newRow);
}
}
else if (newRow < 0)
{
newRow = 0;
log.fine("Set to first Row");
if (log.isLoggable(Level.FINE)) log.fine("Set to first Row");
}

m_mTable.waitLoadingForRow(newRow);
Expand Down Expand Up @@ -3569,6 +3574,9 @@ public int getMaxQueryRecords() {
int tabMaxQueryRecords = m_vo.MaxQueryRecords;
if (roleMaxQueryRecords > 0 && (roleMaxQueryRecords < tabMaxQueryRecords || tabMaxQueryRecords == 0))
tabMaxQueryRecords = roleMaxQueryRecords;
if (tabMaxQueryRecords == 0)
tabMaxQueryRecords = MSysConfig.getIntValue(MSysConfig.GLOBAL_MAX_QUERY_RECORDS,
DEFAULT_GLOBAL_MAX_QUERY_RECORDS, Env.getAD_Client_ID(Env.getCtx()));
return tabMaxQueryRecords;
}

Expand Down
84 changes: 65 additions & 19 deletions org.adempiere.base/src/org/compiere/model/GridTable.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -46,6 +46,7 @@
import javax.swing.event.TableModelListener;
import javax.swing.table.AbstractTableModel;

import org.adempiere.exceptions.AdempiereException;
import org.adempiere.exceptions.DBException;
import org.adempiere.util.ServerContext;
import org.compiere.Adempiere;
Expand Down Expand Up @@ -95,14 +96,15 @@ public class GridTable extends AbstractTableModel
implements Serializable
{
/**
* generated serial id
*
*/
private static final long serialVersionUID = -5564364545827057092L;
private static final long serialVersionUID = -2602189278069194311L;

protected static final String SORTED_DSE_EVENT = "Sorted";

public static final int DEFAULT_GRIDTABLE_LOAD_TIMEOUT_IN_SECONDS = 30;

public static final int DEFAULT_GRIDTABLE_COUNT_TIMEOUT_IN_SECONDS = 1;

public static final String LOAD_TIMEOUT_ERROR_MESSAGE = "GridTabLoadTimeoutError";

public static final String DATA_REFRESH_MESSAGE = "Refreshed";
Expand Down Expand Up @@ -169,6 +171,7 @@ public GridTable(Properties ctx, int AD_Table_ID, String TableName, int WindowNo

/** Rowcount */
private int m_rowCount = 0;
private boolean m_rowCountTimeout = false;
/** Has Data changed? */
private boolean m_changed = false;
/** Index of changed row via SetValueAt */
Expand Down Expand Up @@ -426,7 +429,8 @@ private String createSelectSql()
//IDEMPIERE-5193 Add Limit to Query
if(m_maxRows > 0 && DB.getDatabase().isPagingSupported())
{
m_SQL = DB.getDatabase().addPagingSQL(m_SQL, 1, m_maxRows);
// set to maxRows plus one to trigger FindOverMax on overflow
m_SQL = DB.getDatabase().addPagingSQL(m_SQL, 1, m_maxRows+1);
}

//
Expand Down Expand Up @@ -645,7 +649,8 @@ public boolean open (int maxRows)
m_buffer = new ArrayList<Object[]>(m_rowCount+10);
}
m_sort = new ArrayList<MSort>(m_rowCount+10);
if (m_rowCount > 0)
// actual row count or timeout
if (m_rowCount > 0 || m_rowCountTimeout)
{
m_loader.setContext(ServerContext.getCurrentInstance());
m_loaderFuture = Adempiere.getThreadPoolExecutor().submit(m_loader);
Expand Down Expand Up @@ -1159,7 +1164,7 @@ public void waitLoadingForRow(int row) {
log.warning("Reached " + timeout + " seconds timeout loading row " + (row+1) + " for SQL=" + m_SQL);
//adjust row count
m_rowCount = m_sort.size();
throw new DBException("GridTabLoadTimeoutError");
throw new AdempiereException(Msg.getMsg(Env.getCtx(), LOAD_TIMEOUT_ERROR_MESSAGE));
}
}

Expand Down Expand Up @@ -1266,6 +1271,9 @@ private void fillBuffer(int start, int fetchSize)
try
{
stmt = DB.prepareStatement(sql.toString(), null);
int timeout = MSysConfig.getIntValue(MSysConfig.GRIDTABLE_LOAD_TIMEOUT_IN_SECONDS, DEFAULT_GRIDTABLE_LOAD_TIMEOUT_IN_SECONDS, Env.getAD_Client_ID(Env.getCtx()));
if (timeout > 0)
stmt.setQueryTimeout(timeout);
rs = stmt.executeQuery();
while(rs.next())
{
Expand Down Expand Up @@ -3009,12 +3017,14 @@ protected int open (int maxRows)
// Get Number of Rows
rows = 0;
PreparedStatement pstmt = null;
ResultSet rs = null;
ResultSet rs = null;
m_rowCountTimeout = false;
try
{
pstmt = DB.prepareStatement(m_SQL_Count, get_TrxName());
setParameter (pstmt, true);
int timeout = MSysConfig.getIntValue(MSysConfig.GRIDTABLE_LOAD_TIMEOUT_IN_SECONDS, DEFAULT_GRIDTABLE_LOAD_TIMEOUT_IN_SECONDS, Env.getAD_Client_ID(Env.getCtx()));
int timeout = MSysConfig.getIntValue(MSysConfig.GRIDTABLE_INITIAL_COUNT_TIMEOUT_IN_SECONDS,
DEFAULT_GRIDTABLE_COUNT_TIMEOUT_IN_SECONDS, Env.getAD_Client_ID(Env.getCtx()));
if (timeout > 0)
pstmt.setQueryTimeout(timeout);
rs = pstmt.executeQuery();
Expand All @@ -3023,7 +3033,13 @@ protected int open (int maxRows)
}
catch (SQLException e0)
{
throw new DBException(e0);
if (DB.getDatabase().isQueryTimeout(e0))
{
m_rowCountTimeout = true;
return 0;
}
else
throw new DBException(e0);
}
finally
{
Expand Down Expand Up @@ -3059,11 +3075,7 @@ private void openResultSet() {
try
{
m_pstmt = DB.prepareStatement(m_SQL, trxName);
if (this.maxRows > 0 && rows == this.maxRows)
{
m_pstmt.setMaxRows(this.maxRows);
}
//ensure not all row is fectch into memory for virtual table
//ensure not all rows are fetch into memory for virtual table
if (m_virtual)
m_pstmt.setFetchSize(100);
setParameter (m_pstmt, false);
Expand All @@ -3074,8 +3086,12 @@ private void openResultSet() {
}
catch (SQLException e)
{
log.saveError(e.getLocalizedMessage(), e);
throw new DBException(e);
if (DB.getDatabase().isQueryTimeout(e)) {
throw new AdempiereException(Msg.getMsg(Env.getCtx(), LOAD_TIMEOUT_ERROR_MESSAGE), e);
} else {
log.saveError(e.getLocalizedMessage(), e);
throw new DBException(e);
}
}
}

Expand Down Expand Up @@ -3113,6 +3129,7 @@ public void run()
* Fill buffer from result set
*/
private void doRun() {
boolean isFindOverMax = false;
try
{
openResultSet();
Expand All @@ -3121,6 +3138,11 @@ private void doRun() {

while (m_rs.next())
{
if (maxRows > 0 && m_sort.size() == maxRows) {
isFindOverMax = true;
break;
}

if (Thread.interrupted())
{
if (log.isLoggable(Level.FINE)) log.fine("Interrupted");
Expand All @@ -3144,9 +3166,25 @@ private void doRun() {
}
m_sort.add(sort);

// Start with rowCount=0, inform loading of first row
if (m_rowCountTimeout)
{
m_rowCount++;
if (m_rowCount == 1)
{
DataStatusEvent evt = createDSE();
evt.setLoading(m_sort.size());
evt.setInfo("CountQueryTimeoutLoadBackground", null, false, true);
fireDataStatusChanged(evt);
}
}

// Statement all 1000 rows & sleep
if (m_sort.size() % 1000 == 0)
{
DataStatusEvent evt = createDSE();
evt.setLoading(m_sort.size());
fireDataStatusChanged(evt);
// give the other processes a chance
try
{
Expand All @@ -3159,9 +3197,6 @@ private void doRun() {
close();
return;
}
DataStatusEvent evt = createDSE();
evt.setLoading(m_sort.size());
fireDataStatusChanged(evt);
}
} // while(rs.next())
}
Expand All @@ -3173,6 +3208,17 @@ private void doRun() {
{
close();
}

// Background loading without initial rowCount, inform final loaded rows
if (m_rowCountTimeout && m_sort.size() > 0)
{
DataStatusEvent evt = createDSE();
evt.setLoading(m_sort.size());
if (isFindOverMax)
evt.setInfo("FindOverMax", " > " + m_sort.size(), false, true);
fireDataStatusChanged(evt);
}

fireDataStatusIEvent("", "");
}

Expand Down

0 comments on commit 881e758

Please sign in to comment.