zkLoader Servlet - Avg. Request Service Time (ms)

asked 2017-03-16 14:49:06 +0800

shuklajay1994
1

We having issue of ZKLoader Avg.Request Service Time(ms). We facing this issue many times and We tried to resolve it we made also some changes but it's not working. Here i am attached Application and DB logs When ZKLoader alert came.

Application Log:-

06:12:16.072===========> ExtMUser.saveError: SaveError - EMail format is invalid: EMail Address - [[email protected]] [183] 06:12:16.072===========> Login.getClients: Failed to update user record with date last login [183] 07:22:31.019===========> ExtMUser.saveError: SaveError - EMail format is invalid: EMail Address - [[email protected]] [175] 07:22:31.020===========> Login.getClients: Failed to update user record with date last login [175] 07:28:40.457===========> ExtMUser.saveError: SaveError - EMail format is invalid: EMail Address - [[email protected]] [180] 07:28:40.457===========> Login.getClients: Failed to update user record with date last login [180] 07:36:14.503===========> ExtMUser.saveError: SaveError - EMail format is invalid: EMail Address - [[email protected]] [177] 07:36:14.504===========> Login.getClients: Failed to update user record with date last login [177] 08:53:32.484===========> GridField.createDefault: Created - Unparseable date: "SYSDATE" [195] 08:53:32.518===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [195] 08:53:32.563===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [195] 08:53:32.620===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [195] 08:53:32.688===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [195] 08:53:51.488===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [192] 08:53:51.522===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [192] 08:53:51.559===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [192] 08:53:51.597===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [192] 08:53:55.733===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [180] 08:54:02.508===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [195] 08:54:02.555===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [195] 08:54:02.596===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [195] 08:54:15.156===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [192] 08:55:09.083===========> Trx.commit: POSaveMInOut09a2e922-3ff3-42a3-9818-f3d901a16037 [195] org.postgresql.util.PSQLException: ERROR: insert or update on table "minout" violates foreign key constraint "celementvalueuser1minout" Detail: Key (user1id)=(0) is not present in table "celementvalue".; State=23503; ErrorCode=0 at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2182) at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1911) at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:173) at org.postgresql.jdbc2.AbstractJdbc2Connection.executeTransactionCommand(AbstractJdbc2Connection.java:824) at org.postgresql.jdbc2.AbstractJdbc2Connection.commit(AbstractJdbc2Connection.java:848) at com.mchange.v2.c3p0.impl.NewProxyConnection.commit(NewProxyConnection.java:1007) at org.compiere.util.Trx.commit(Trx.java:357) at org.compiere.util.Trx.commit(Trx.java:399) at org.compiere.model.PO.save(PO.java:2133) at org.compiere.model.GridTable.dataSavePO(GridTable.java:2190) at org.compiere.model.GridTable.dataSave(GridTable.java:1516) at org.compiere.model.GridTab.dataSave(GridTab.java:963) at org.adempiere.webui.adwindow.ADTabpanel.dataSave(ADTabpanel.java:1772) at org.adempiere.webui.adwindow.CompositeADTabbox.dataSave(CompositeADTabbox.java:1098) at org.adempiere.webui.adwindow.AbstractADWindowContent.onSave0(AbstractADWindowContent.java:2426) at org.adempiere.webui.adwindow.AbstractADWindowContent.onSaveCallback(AbstractADWindowContent.java:2385) at org.adempiere.webui.adwindow.AbstractADWindowContent.access$19(AbstractADWindowContent.java:2372) at org.adempiere.webui.adwindow.AbstractADWindowContent$28.onCallback(AbstractADWindowContent.java:2346) at org.adempiere.webui.adwindow.AbstractADWindowContent$28.onCallback(AbstractADWindowContent.java:1) at org.adempiere.webui.adwindow.validator.WindowValidatorManager$ChainCallback.start(WindowValidatorManager.java:124) at org.adempiere.webui.adwindow.validator.WindowValidatorManager.fireWindowValidatorEvent(WindowValidatorManager.java:103)

08:55:09.083===========> Trx.saveError: DeleteErrorDependent - ERROR: insert or update on table "minout" violates foreign key constraint "celementvalueuser1minout" Detail: Key (user1id)=(0) is not present in table "celementvalue". [195] 08:56:27.844===========> GridField.createDefault: Created - Unparseable date: "SYSDATE" [172] 08:56:27.871===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [172] 08:56:27.901===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [172] 08:56:27.946===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [172] 08:56:28.012===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [172] 08:56:34.064===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [185] 08:56:34.100===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [185] 08:56:34.138===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [185] 08:56:34.177===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [185] 08:56:37.334===========> Evaluator.evaluateLogicTuple: Logic tuple does not comply with format '@context@=value' where operand could be one of '=!^><' => 'API'= [181]

DB log:-

2017-03-16 12:49:29 UTC::@:[2577]:LOG: checkpoint complete: wrote 407 buffers (0.1%); 0 transaction log file(s) added, 0 removed, 2 recycled; write=40.964 s, sync=0.025 s, total=41.033 s; sync files=81, longest=0.024 s, average=0.000 s 2017-03-16 12:53:31 UTC:172.31.22.169(58258):adempiere@idempiere:[22817]:ERROR: permission denied for database rdsadmin 2017-03-16 12:53:31 UTC:172.31.22.169(58258):adempiere@idempiere:[22817]:STATEMENT: SELECT pgdatabasesize('rdsadmin') size 2017-03-16 12:53:48 UTC::@:[2577]:LOG: checkpoint starting: time 2017-03-16 12:54:48 UTC::@:[2577]:LOG: checkpoint complete: wrote 594 buffers (0.1%); 0 transaction log file(s) added, 0 removed, 1 recycled; write=59.677 s, sync=0.011 s, total=59.712 s; sync files=167, longest=0.010 s, average=0.000 s 2017-03-16 12:54:54 UTC:172.31.25.101(48892):adempiere@idempiere:[23019]:ERROR: insert or update on table "minout" violates foreign key constraint "celementvalueuser1minout" 2017-03-16 12:54:54 UTC:172.31.25.101(48892):adempiere@idempiere:[23019]:DETAIL: Key (user1id)=(0) is not present in table "celementvalue". 2017-03-16 12:54:54 UTC:172.31.25.101(48892):adempiere@idempiere:[23019]:STATEMENT: COMMIT 2017-03-16 12:58:48 UTC::@:[2577]:LOG: checkpoint starting: time 2017-03-16 12:59:48 UTC::@:[2577]:LOG: checkpoint complete: wrote 593 buffers (0.1%); 0 transaction log file(s) added, 0 removed, 1 recycled; write=59.611 s, sync=0.011 s, total=59.650 s; sync files=165, longest=0.011 s, average=0.000 s

We faced zkloader issue when in above logs processes running. and also we have configured ZKLoader for monitoring on monitoring system(NMS).