Skip to main content

This content is closed to future replies and is no longer being maintained or updated.
Links may no longer function. If you have a similar request, please write a new post.

Question

10
Replies
1691
Views
PradeepPydi Member since 2017 240 posts
Anthem
Posted: Jun 25, 2018
Last activity: May 14, 2019
Closed

RequestorLockExceptions followed by thread dumps causing slowness.

Hi Team,

We could find a lot of RequestorLockExceptions followed by thread dumps in our development environment.Eventually these exceptions are causing slowness issues in our environments.

Please find the error stack below.

Show More

Hi Team,

We could find a lot of RequestorLockExceptions followed by thread dumps in our development environment.Eventually these exceptions are causing slowness issues in our environments.

Please find the error stack below.

2018-06-25 14:27:23,344 [130.232-8887-exec-60] [ ] [ ] [ ] (ngineinterface.service.HttpAPI) ERROR xx.xx.xx.xx|xx.xx.xx.xx - : com.pega.pegarules.pub.context.RequestorLockException
com.pega.pegarules.pub.context.RequestorLockException: Unable to synchronize on requestor HPTP38B3BDGCTQP3BYARRYC15YBODPOOZ within 120 seconds: (thisThread = https-jsse-nio2-xx.xx.xx.xx-8887-exec-60) (originally locked by = https-jsse-nio2-xx.xx.xx.xx-8887-exec-53) (finally locked by = https-jsse-nio2-xx.xx.xx.xx-8887-exec-53)
at com.pega.pegarules.session.internal.PRSessionProviderImpl.throwRequestorLockException(PRSessionProviderImpl.java:1520) ~[prprivate.jar:?]
at com.pega.pegarules.session.internal.PRSessionProviderImpl.getLockOnRequestor(PRSessionProviderImpl.java:1504) ~[prprivate.jar:?]
at com.pega.pegarules.session.internal.PRSessionProviderImpl.doWithRequestorLocked(PRSessionProviderImpl.java:1061) ~[prprivate.jar:?]
at com.pega.pegarules.session.internal.PRSessionProviderImpl.doWithRequestorLocked(PRSessionProviderImpl.java:930) ~[prprivate.jar:?]
at com.pega.pegarules.session.external.engineinterface.service.EngineAPI.processRequest(EngineAPI.java:336) ~[prenginext.jar:?]
at com.pega.pegarules.session.internal.engineinterface.service.HttpAPI.invoke(HttpAPI.java:854) ~[prprivate.jar:?]
at com.pega.pegarules.session.internal.engineinterface.etier.impl.EngineImpl._invokeEngine_privact(EngineImpl.java:331) ~[prprivate.jar:?]
at com.pega.pegarules.session.internal.engineinterface.etier.impl.EngineImpl.invokeEngine(EngineImpl.java:274) ~[prprivate.jar:?]
at com.pega.pegarules.session.internal.engineinterface.etier.impl.EngineImpl.invokeEngine(EngineImpl.java:251) ~[prprivate.jar:?]
at com.pega.pegarules.priv.context.JNDIEnvironment.invokeEngineInner(JNDIEnvironment.java:278) ~[prpublic.jar:?]
at com.pega.pegarules.priv.context.JNDIEnvironment.invokeEngine(JNDIEnvironment.java:223) ~[prpublic.jar:?]
at com.pega.pegarules.web.impl.WebStandardImpl.makeEtierRequest(WebStandardImpl.java:678) ~[prwebj2ee.jar:?]
at com.pega.pegarules.web.impl.WebStandardImpl.doPost(WebStandardImpl.java:394) ~[prwebj2ee.jar:?]
at sun.reflect.GeneratedMethodAccessor104.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_151]
at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_151]
at com.pega.pegarules.internal.bootstrap.PRBootstrap.invokeMethod(PRBootstrap.java:370) ~[prbootstrap-7.2.2-117.jar:7.2.2-117]
at com.pega.pegarules.internal.bootstrap.PRBootstrap.invokeMethodPropagatingThrowable(PRBootstrap.java:411) ~[prbootstrap-7.2.2-117.jar:7.2.2-117]
at com.pega.pegarules.boot.internal.extbridge.AppServerBridgeToPega.invokeMethodPropagatingThrowable(AppServerBridgeToPega.java:224) ~[prbootstrap-api-7.2.2-117.jar:7.2.2-117]
at com.pega.pegarules.boot.internal.extbridge.AppServerBridgeToPega.invokeMethod(AppServerBridgeToPega.java:273) ~[prbootstrap-api-7.2.2-117.jar:7.2.2-117]
at com.pega.pegarules.internal.web.servlet.WebStandardBoot.doPost(WebStandardBoot.java:121) ~[prbootstrap-api-7.2.2-117.jar:7.2.2-117]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:661) ~[servlet-api.jar:?]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:742) ~[servlet-api.jar:?]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:230) ~[catalina.jar:8.5.13]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) ~[catalina.jar:8.5.13]
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) ~[tomcat-websocket.jar:8.5.13]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192) ~[catalina.jar:8.5.13]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) ~[catalina.jar:8.5.13]
at org.apache.catalina.filters.ExpiresFilter.doFilter(ExpiresFilter.java:1230) ~[catalina.jar:8.5.13]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192) ~[catalina.jar:8.5.13]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) ~[catalina.jar:8.5.13]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) ~[catalina.jar:8.5.13]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) ~[catalina.jar:8.5.13]
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:595) ~[catalina.jar:8.5.13]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) ~[catalina.jar:8.5.13]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80) ~[catalina.jar:8.5.13]
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:624) ~[catalina.jar:8.5.13]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) ~[catalina.jar:8.5.13]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:341) ~[catalina.jar:8.5.13]
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:799) ~[tomcat-coyote.jar:8.5.13]
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) ~[tomcat-coyote.jar:8.5.13]
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:861) ~[tomcat-coyote.jar:8.5.13]
at org.apache.tomcat.util.net.Nio2Endpoint$SocketProcessor.doRun(Nio2Endpoint.java:1697) ~[tomcat-coyote.jar:8.5.13]
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-coyote.jar:8.5.13]
at org.apache.tomcat.util.net.AbstractEndpoint.processSocket(AbstractEndpoint.java:934) ~[tomcat-coyote.jar:8.5.13]
at org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper$4.completed(Nio2Endpoint.java:626) ~[tomcat-coyote.jar:8.5.13]
at org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper$4.completed(Nio2Endpoint.java:604) ~[tomcat-coyote.jar:8.5.13]
at org.apache.tomcat.util.net.SecureNio2Channel$1.completed(SecureNio2Channel.java:877) ~[tomcat-coyote.jar:8.5.13]
at org.apache.tomcat.util.net.SecureNio2Channel$1.completed(SecureNio2Channel.java:810) ~[tomcat-coyote.jar:8.5.13]
at sun.nio.ch.Invoker.invokeUnchecked(Unknown Source) ~[?:1.8.0_151]
at sun.nio.ch.Invoker$2.run(Unknown Source) ~[?:1.8.0_151]
at sun.nio.ch.AsynchronousChannelGroupImpl$1.run(Unknown Source) ~[?:1.8.0_151]
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [?:1.8.0_151]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [?:1.8.0_151]
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-util.jar:8.5.13]
at java.lang.Thread.run(Unknown Source) [?:1.8.0_151]

Show Less
To see attachments, please log in.
Low-Code App Development
System Administration

Posted: 6 years ago

I have analyzed the thread dumps and usually it is followed by the below mentioned error in the log.

2018-06-25 13:10:08,735 [130.232-8887-exec-48] [          ] [                    ] [                    ] (      web.impl.WebStandardImpl) WARN    - I/O Exception occurred while writing or flushing the stream 
org.apache.catalina.connector.ClientAbortException: java.io.IOException: An established connection was aborted by the software in your host machine.

Caused by: java.io.IOException: An established connection was aborted by the software in your host machine

To see attachments, please log in.
Posted: 6 years ago

Hi Pradeep,

Please check withing the threadump that precedes the requestor lock exception for https-jsse-nio2-xx.xx.xx.xx-8887-exec-53 at runable state.
The stack trace for the mentioned thread should give good idea on where the execution is stuck.

Regards,
Ujjwal


 

To see attachments, please log in.
Posted: 6 years ago

Hi Pradeep,

 

Could you please attach the complete Pega-RULES and Pega-ALERT logs in the post.

We might need to check the pega-alert logs in the same time if any alerts are being generated or not.

Also complete stack trace would help us knowing the cause of the thread dumps.

 

Regards,

Vikash

To see attachments, please log in.
Posted: 6 years ago

Hi Pradeep,

The alert log that you have given is from 18:00:00hrs. but the thread dump occurred at 14:12:06.

Could you please check what all alerts you can notice in the alert logs near this time range with respect to requester https-jsse-nio2- Proprietary information hidden-8887-exec-36.

Also from the logs it looks like there is some long running query , so please check for the same in the alert log with respect to the particular thread and optimize the query if required.

 

Regards,

Vikash

To see attachments, please log in.
Posted: 6 years ago

Hi,

Can you please check for PEGA005 logs in the Pega-ALERT log file. It should give you the idea which queries are taking more time, which might be affecting performance in this case.

Please provide PRPC version as well.

Regards,

Rachit

To see attachments, please log in.
Posted: 6 years ago

Requestor is HDJD66Y58ZMZ15I58Q3YGDYJOZ24GB643  locked by thread "https-jsse-nio2- Proprietary information hidden-8887-exec-36" and below is the thread state

 

"https-jsse-nio2- Proprietary information hidden-8887-exec-36" Id=624 in RUNNABLE

BlockedCount : 16, BlockedTime : -1, WaitedCount : 1064, WaitedTime : -1

    at java.net.SocketInputStream.socketRead0(Native Method)

    at java.net.SocketInputStream.socketRead(Unknown Source)

    at java.net.SocketInputStream.read(Unknown Source)

    at java.net.SocketInputStream.read(Unknown Source)

    at com.microsoft.sqlserver.jdbc.TDSChannel$ProxyInputStream.readInternal(IOBuffer.java:955)

    at com.microsoft.sqlserver.jdbc.TDSChannel$ProxyInputStream.read(IOBuffer.java:943)

    at sun.security.ssl.InputRecord.readFully(Unknown Source)

    at sun.security.ssl.InputRecord.read(Unknown Source)

    at sun.security.ssl.SSLSocketImpl.readRecord(Unknown Source)

      - locked java.lang.Object@395c6790

    at sun.security.ssl.SSLSocketImpl.readDataRecord(Unknown Source)

    at sun.security.ssl.AppInputStream.read(Unknown Source)

      - locked sun.security.ssl.AppInputStream@6d7c544a

    at com.microsoft.sqlserver.jdbc.TDSChannel.read(IOBuffer.java:1877)

    at com.microsoft.sqlserver.jdbc.TDSReader.readPacket(IOBuffer.java:6642)

Show More

Requestor is HDJD66Y58ZMZ15I58Q3YGDYJOZ24GB643  locked by thread "https-jsse-nio2- Proprietary information hidden-8887-exec-36" and below is the thread state

 

"https-jsse-nio2- Proprietary information hidden-8887-exec-36" Id=624 in RUNNABLE

BlockedCount : 16, BlockedTime : -1, WaitedCount : 1064, WaitedTime : -1

    at java.net.SocketInputStream.socketRead0(Native Method)

    at java.net.SocketInputStream.socketRead(Unknown Source)

    at java.net.SocketInputStream.read(Unknown Source)

    at java.net.SocketInputStream.read(Unknown Source)

    at com.microsoft.sqlserver.jdbc.TDSChannel$ProxyInputStream.readInternal(IOBuffer.java:955)

    at com.microsoft.sqlserver.jdbc.TDSChannel$ProxyInputStream.read(IOBuffer.java:943)

    at sun.security.ssl.InputRecord.readFully(Unknown Source)

    at sun.security.ssl.InputRecord.read(Unknown Source)

    at sun.security.ssl.SSLSocketImpl.readRecord(Unknown Source)

      - locked java.lang.Object@395c6790

    at sun.security.ssl.SSLSocketImpl.readDataRecord(Unknown Source)

    at sun.security.ssl.AppInputStream.read(Unknown Source)

      - locked sun.security.ssl.AppInputStream@6d7c544a

    at com.microsoft.sqlserver.jdbc.TDSChannel.read(IOBuffer.java:1877)

    at com.microsoft.sqlserver.jdbc.TDSReader.readPacket(IOBuffer.java:6642)

      - locked com.microsoft.sqlserver.jdbc.TDSReader@7110160d

    at com.microsoft.sqlserver.jdbc.TDSCommand.startResponse(IOBuffer.java:7959)

    at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.doExecutePreparedStatement(SQLServerPreparedStatement.java:438)

    at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement$PrepStmtExecCmd.doExecute(SQLServerPreparedStatement.java:385)

    at com.microsoft.sqlserver.jdbc.TDSCommand.execute(IOBuffer.java:7505)

    at com.microsoft.sqlserver.jdbc.SQLServerConnection.executeCommand(SQLServerConnection.java:2445)

      - locked java.lang.Object@6cec1ea0

    at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeCommand(SQLServerStatement.java:191)

    at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeStatement(SQLServerStatement.java:166)

    at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.execute(SQLServerPreparedStatement.java:367)

    at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown Source)

    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)

    at java.lang.reflect.Method.invoke(Unknown Source)

    at org.apache.tomcat.jdbc.pool.StatementFacade$StatementProxy.invoke(StatementFacade.java:138)

    at com.sun.proxy.$Proxy11.execute(Unknown Source)

    at com.pega.pegarules.data.internal.store.DatabasePreparedStatementImpl.execute(DatabasePreparedStatementImpl.java:504)

    at com.pega.pegarules.data.internal.access.Lister.listWithResultPackager(Lister.java:399)

    at com.pega.pegarules.data.internal.access.Lister.list(Lister.java:185)

    at com.pega.pegarules.data.internal.access.DBQueryExecutor.executeRDB(DBQueryExecutor.java:123)

    at com.pega.pegarules.data.internal.access.DBQueryExecutor.executeRDB(DBQueryExecutor.java:74)

    at com.pega.pegarules.data.internal.access.DatabaseImpl.executeRDB(DatabaseImpl.java:3084)

    at com.pega.pegarules.data.internal.access.DatabaseImpl.executeRDB(DatabaseImpl.java:3064)

    at com.pega.pegarules.generation.internal.cache.appcentric.AppShortcutImpl.dependencyOverriddenInBranchRulesets(AppShortcutImpl.java:245)

    at com.pega.pegarules.generation.internal.cache.appcentric.AppShortcutImpl.getInferredACCacheShortcut(AppShortcutImpl.java:663)

    at com.pega.pegarules.generation.internal.cache.appcentric.RACacheAppCentricImpl.inferGeneratedJavaFromExistingEntry(RACacheAppCentricImpl.java:2322)

    at com.pega.pegarules.generation.internal.cache.appcentric.RACacheAppCentricImpl.find(RACacheAppCentricImpl.java:977)

    at com.pega.pegarules.generation.internal.cache.AssemblyCacheWrapper.find(AssemblyCacheWrapper.java:797)

    at com.pega.pegarules.generation.internal.assembly.FUAManagerImpl.getInternal(FUAManagerImpl.java:1414)

    at com.pega.pegarules.generation.internal.assembly.FUAManagerImpl.get(FUAManagerImpl.java:1303)

    at com.pega.pegarules.generation.internal.PRGenProviderImpl.get(PRGenProviderImpl.java:500)

    at com.pega.pegarules.session.internal.mgmt.StreamBuilderTools.appendStreamKeepProperties(StreamBuilderTools.java:762)

    at com.pega.pegarules.session.internal.mgmt.autostreams.IncludeStreamRuntime.getStream(IncludeStreamRuntime.java:332)

    at com.pega.pegarules.session.internal.mgmt.autostreams.IncludeStreamRuntime.emitIncludeStreamReference(IncludeStreamRuntime.java:252)

    at com.pega.pegarules.session.internal.mgmt.autostreams.AutoStreamRuntimeImpl.emitIncludeStreamReference(AutoStreamRuntimeImpl.java:409)

    at com.pega.pegarules.session.internal.mgmt.autostreams.uicomponent.context.ContextProcessor.emitIncludeStream(ContextProcessor.java:1210)

    at com.pega.pegarules.session.internal.mgmt.autostreams.uicomponent.context.ContextProcessor.executeSection(ContextProcessor.java:1019)

    at com.pega.pegarules.session.internal.mgmt.autostreams.uicomponent.context.ContextProcessor.processSection(ContextProcessor.java:994)

    at com.pega.pegarules.session.internal.mgmt.autostreams.uicomponent.context.ContextProcessor.processSection(ContextProcessor.java:1232)

    at com.pega.pegarules.session.internal.mgmt.autostreams.uicompone

 

After verifying the alert logs PEGA0037 alerts has been generated for the same requestor

 

Rule assembly process has exceeded the threshold of 400 ms: 669 ms. Details: ;Total Rule assembly process: ELAPSED time = 669;CPU time = 0;Delta Java assembly process: Delta Assembly ELAPSED time = 669;Delta Assembly CPU time = 0;Delta Compile process: Delta Compile ELAPSED time = 0;Delta Compile CPU time = 0;Assembled class name = com.pegarules.generated.html_section.ra_stream_pygridnoresultsmessage_2e0fdde9c2f98a23b873411cb5724bab;Assembled class size = 26,387;Rules count = 2;Personal Ruleset = AF73546@;AccessGroup = AntmCPMHC:SysAdmin;Application = AntmCSNCCSuper 01.01.01;FuaKeys = RULE-HTML-SECTION|RULE-TEST-UNIT-CASE!PYGRIDNORESULTSMESSAGE;STREAM|AntmCSNCCSuper!01.01.01$932c17d2718b55e1e1baf09e08335ae8

 

You can run the static assembler from the ( Designer Studio - System - Assembly - Static Assembler ) to assemble the rules here .

 

Let us know if you have any further queries .

Cheers,

Arun

 


Show Less
To see attachments, please log in.
Posted: 5 years ago

Hi,

Thank you for posting your query in the PSC. This looks like an inactive post and hence, we suggest you create a new post for your query. Click on the Write Post button here. Once created, please reply back here with the URL of the new post.

You may also refer this discussion link as a reference in the new thread.

To see attachments, please log in.

We'd prefer it if you saw us at our best.

Pega Collaboration Center has detected you are using a browser which may prevent you from experiencing the site as intended. To improve your experience, please update your browser.

Close Deprecation Notice