We're here to help

Slowness in the application - Helpful tips reviewing logs

Applicable Product:

PeopleFluent Learning (On-Premise customers)

 

Applicable Release:

All versions

 

Summary:

Several factors can lead to performance issues in the application. 

This article lists a few symptoms along with how you can work towards determining a cause via the EKP log files.

 

Connection timeout

  • Large bulk loading tasks

Sample log excerpts in ekp.log when a transaction 'dataloaderimporter' has not completed after “N” minute(s)

 

YYYY/MMM/DD hh:mm:ss Severity(ERROR) Source(com.netdimen.ob.c.e.c): DEFAULT: Aborting connection held too long; Connection replaced: dataloaderimporter/”userid” : 56878901

-where 56878901 is seconds

YYYY/MMM/DD hh:mm:ss ERROR com.netdimen.ai.j.f.d: Data Loader Errorcom.microsoft.sqlserver.jdbc.SQLServerException: The connection is closed.
at com.microsoft.sqlserver.jdbc.SQLServerException.makeFromDriverError(Unknown Source)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.checkClosed(Unknown Source)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.getAutoCommit(Unknown Source)

 

The connection was closed due to the long time it is being used by the LMS to upload the data.This could be due to the amount of data the bulk loading task is trying to process. One workaround is to break the file up into smaller batches. 

The parameter system.connectionTimeLimit= in ekp.properties sets the connection timeout from 60 minutes (default if not specified) and can be increased up to 3 hours or more, which should be reasonable especially for data loaders, course uploads, large reports etc.

 

  • Large reports

Sample log entry:

YYYY/MMM/DD hh:mm:ss ERROR com.netdimen.txserver.TransactionContainer.a: SQLEXCEPTION: Socket closed ErrorCode: 0 State: 08S01
YYYY/MMM/DD hh:mm:ss ERROR com.netdimen.txserver.TransactionContainer.a: SYSTEM EXCEPTION (EKP005543905) for user 'userid(internal userid)', tx 'turboreports'.
Referring URL: http://localhost:8080/ts2211/servlet/ekp
QueryString: null
java.lang.RuntimeException: com.microsoft.sqlserver.jdbc.SQLServerException: Socket closed
at com.netdimen.A.a.j.a(j.java:153)

 

This could be due to the amount of data the report is trying to process in generating the report. The connection was closed due to the long time it is being used by the LMS to generate the data of the report.

The parameter system.connectionTimeLimit= in ekp.properties sets the connection timeout from 60 minutes (default if not specified) and can be increased up to 3 hours or more, which should be reasonable especially for data loaders, course uploads, large reports etc.

 

 

  • Connections running out

Log entry:

YYYY/MMM/DD hh:mm:ss INFO com.netdimen.sql.ConnectionPool.allocateConnections: DEFAULT: Allocated 5 new database connections.
YYYY/MMM/DD hh:mm:ss INFO com.netdimen.sql.ConnectionPool.allocateConnections: DEFAULT: Allocated 5 new database connections.
YYYY/MMM/DD hh:mm:ss INFO com.netdimen.sql.ConnectionPool.allocateConnections: DEFAULT: Allocated 5 new database connections.
YYYY/MMM/DD hh:mm:ss INFO com.netdimen.sql.ConnectionPool.allocateConnections: DEFAULT: Allocated 5 new database connections.
YYYY/MMM/DD hh:mm:ss INFO com.netdimen.sql.ConnectionPool.allocateConnections: DEFAULT: Allocated 5 new database connections.
YYYY/MMM/DD hh:mm:ss INFO com.netdimen.sql.ConnectionPool.allocateConnections: DEFAULT: Allocated 5 new database connections.
YYYY/MMM/DD hh:mm:ss INFO com.netdimen.sql.ConnectionPool.allocateConnections: DEFAULT: Allocated 5 new database connections.
YYYY/MMM/DD hh:mm:ss INFO com.netdimen.sql.ConnectionPool.allocateConnections: DEFAULT: Allocated 5 new database connections.
YYYY/MMM/DD hh:mm:ss INFO com.netdimen.sql.ConnectionPool.allocateConnections: DEFAULT: Allocated 5 new database connections.
YYYY/MMM/DD hh:mm:ss WARNING com.netdimen.sql.ConnectionPool.startDeadlockTimer: DEFAULT: System connection pool being heavily used. More may be needed.

The ekp.log indicates System connection pool being heavily used. More may be needed could be alleviated by increasing the parameter default.maxConnections= in ekp.properties. Continue to monitor the logs in the event the issue persists and additional connections are needed.

 

A review of the logs can help identify how the database connections were being occupied.

If there are transactions that have not been completed for quite a while (like below), it may indicate there is a performance issue and some incomplete transactions are holding on to the allotted number of connections. This indicates connections are not freeing up to allow new connections. If that's the case, please send PeopleFluent support the full log for investigation into why they are not completing.

 

Transaction 'dataloaderimporter' has not completed after 70 minute(s)
YYYY/MMM/DD hh:mm:ss Severity(ERROR) Source(com.netdimen.ob.c.e.c): DEFAULT: Aborting connection held too long; Connection replaced: dataloaderimporter/userid : 1280821653250

 

The below example shows someone attempting to clone a session in Catalog Editor, but are unable to due to an underlying performance issue in the application.

 

YYYY/MMM/DD hh:mm:ss INFO com.netdimen.Y.w.a: DEFAULT: Con #0, Status: In Use, Last User: loginnotification/userid, ElapsedTime: 0:22:41.835

YYYY/MMM/DD hh:mm:ss INFO com.netdimen.Y.w.a: DEFAULT: Con #1, Status: In Use, Last User: loginnotification/userid, ElapsedTime: 0:24:23.597

YYYY/MMM/DD hh:mm:ss INFO com.netdimen.Y.w.a: DEFAULT: Con #2, Status: In Use, Last User: tablistsessions/userid, ElapsedTime: 0:28:19.787

YYYY/MMM/DD hh:mm:ss INFO com.netdimen.Y.w.a: DEFAULT: Con #3, Status: In Use, Last User: bscatframes/userid, ElapsedTime: 0:26:19.161

YYYY/MMM/DD hh:mm:ss INFO com.netdimen.Y.w.a: DEFAULT: Con #4, Status: In Use, Last User: bscatframes/userid, ElapsedTime: 0:24:26.617

YYYY/MMM/DD hh:mm:ss INFO com.netdimen.Y.w.a: DEFAULT: Con #5, Status: In Use, Last User: ConnectionPool[Default], ElapsedTime: 0:29:34.455

YYYY/MMM/DD hh:mm:ss INFO com.netdimen.Y.w.a: DEFAULT: Con #6, Status: In Use, Last User: bscatframes/userid, ElapsedTime: 0:29:03.576

YYYY/MMM/DD hh:mm:ss INFO com.netdimen.Y.w.a: DEFAULT: Con #7, Status: In Use, Last User: bscatframes/userid, ElapsedTime: 0:29:18.774

YYYY/MMM/DD hh:mm:ss INFO com.netdimen.Y.w.a: DEFAULT: Con #8, Status: In Use, Last User: ConnectionPool[Default], ElapsedTime: 0:29:39.333

YYYY/MMM/DD hh:mm:ss INFO com.netdimen.Y.w.a: DEFAULT: Con #9, Status: In Use, Last User: ConnectionPool[Default], ElapsedTime: 0:29:44.706

YYYY/MMM/DD hh:mm:ss INFO com.netdimen.Y.w.a: DEFAULT: Con #10, Status: In Use, Last User: LEARNINGMODULEMANAGER/userid, ElapsedTime: 0:29:39.331

YYYY/MMM/DD hh:mm:ss INFO com.netdimen.Y.w.a: DEFAULT: Con #11, Status: In Use, Last User: bscatframes/userid, ElapsedTime: 0:28:52.230

YYYY/MMM/DD hh:mm:ss INFO com.netdimen.Y.w.a: DEFAULT: Con #12, Status: In Use, Last User: loginnotification/userid, ElapsedTime: 0:29:24.858

YYYY/MMM/DD hh:mm:ss INFO com.netdimen.Y.w.a: DEFAULT: Con #13, Status: In Use, Last User: LEARNINGMODULEMANAGER/userid, ElapsedTime: 0:29:44.706

YYYY/MMM/DD hh:mm:ss INFO com.netdimen.Y.w.a: DEFAULT: Con #14, Status: In Use, Last User: clonemodulesession/userid, ElapsedTime: 0:31:22.896

YYYY/MMM/DD hh:mm:ss INFO com.netdimen.Y.w.a: DEFAULT: Con #15, Status: In Use, Last User: LEARNINGMODULEMANAGER/userid, ElapsedTime: 0:29:34.454

YYYY/MMM/DD hh:mm:ss INFO com.netdimen.Y.w.a: DEFAULT: OLDEST IN-USE SLOT IS #14

 

If the system performance is significantly slow, there is a way to reset database connections in the pool without restarting the service. You can go to the System Administration Manager->System Statistics->Connection Statistics and press the Reset Connection Pool button. This is only suggested for desperately slow performance as all the database connections (activities) would be reset.This will result in the end users experiencing errors in the application until their connection is reestablished. If a user is running reports, the report will not complete and the user will get an error.

 

  • Deadlocks

Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: Transaction (Process ID 214) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.

 

When a transaction execution on the database is taking an extensively long time, it may hold the database table causing a block to other transactions on said table leading to deadlock errors.

To alleviate deadlocks, one suggestion is to configure the default.connectionPoolTestInterval=1 in ekp.properties to do an integrity test for each use of a database connection to check to see if it's dead or idle and return it back to the pool if so. But if this doesn't help then package up the full log and send to PeopleFluent Support

Was this article helpful?
0 out of 0 found this helpful
Return to top