Gil Portenseigne created OFBIZ-11204:
----------------------------------------
Summary: Remove unwanted error log by `ServiceSemaphore` waiting
process
Key: OFBIZ-11204
URL: https://issues.apache.org/jira/browse/OFBIZ-11204
Project: OFBiz
Issue Type: Improvement
Components: framework
Affects Versions: Trunk
Reporter: Gil Portenseigne
Assignee: Gil Portenseigne
When a lot of semaphore configured service instances are running in a short
period, multiple errors of this type are logged :
{code:none}
// | 2019-09-19 14:47:44.000 | 2019-09-19 16:47:44,692 |OFBiz-JobQueue-2
|GenericDelegator |E| Failure in create operation for entity
[ServiceSemaphore]: org.apache.ofbiz.entity.GenericEntityException: Error while
inserting: [GenericEntity:ServiceSemaphore][createdStamp,2019-09-19
16:47:44.678(java.sql.Timestamp)][createdTxStamp,2019-09-19
16:47:44.678(java.sql.Timestamp)][lastUpdatedStamp,2019-09-19
16:47:44.678(java.sql.Timestamp)][lastUpdatedTxStamp,2019-09-19
16:47:44.678(java.sql.Timestamp)][lockThread,OFBiz-JobQueue-2(java.lang.String)][lockTime,2019-09-19
16:47:44.676(java.sql.Timestamp)][lockedByInstanceId,emb-ofbiz-prd-technical-asg-20171209-01-eu-west-1b(java.lang.String)][serviceName,xxx(java.lang.String)]
(SQL Exception while executing the following:INSERT INTO
public.SERVICE_SEMAPHORE (SERVICE_NAME, LOCKED_BY_INSTANCE_ID, LOCK_THREAD,
LOCK_TIME, LAST_UPDATED_STAMP, LAST_UPDATED_TX_STAMP, CREATED_STAMP,
CREATED_TX_STAMP) VALUES (?, ?, ?, ?, ?, ?, ?, ?) (ERROR: duplicate key value
violates unique constraint "pk_service_semaphore" Detail: Key
(service_name)=(xxx) already exists.)). Rolling back transaction.
|
| 2019-09-19 14:47:44.000 | 2019-09-19 16:47:44,692 |OFBiz-JobQueue-2
|ServiceSemaphore |E| null
|
| 2019-09-19 14:47:44.000 | org.apache.ofbiz.entity.GenericEntityException:
org.apache.ofbiz.entity.GenericEntityException: Error while inserting:
[GenericEntity:ServiceSemaphore][createdStamp,2019-09-19
16:47:44.678(java.sql.Timestamp)][createdTxStamp,2019-09-19
16:47:44.678(java.sql.Timestamp)][lastUpdatedStamp,2019-09-19
16:47:44.678(java.sql.Timestamp)][lastUpdatedTxStamp,2019-09-19
16:47:44.678(java.sql.Timestamp)][lockThread,OFBiz-JobQueue-2(java.lang.String)][lockTime,2019-09-19
16:47:44.676(java.sql.Timestamp)][lockedByInstanceId,emb-ofbiz-prd-technical-asg-20171209-01-eu-west-1b(java.lang.String)][serviceName,xxx(java.lang.String)]
(SQL Exception while executing the following:INSERT INTO
public.SERVICE_SEMAPHORE (SERVICE_NAME, LOCKED_BY_INSTANCE_ID, LOCK_THREAD,
LOCK_TIME, LAST_UPDATED_STAMP, LAST_UPDATED_TX_STAMP, CREATED_STAMP,
CREATED_TX_STAMP) VALUES (?, ?, ?, ?, ?, ?, ?, ?) (ERROR: duplicate key value
violates unique constraint "pk_service_semaphore" Detail: Key
(service_name)=(xxx) already exists.)) (Error while inserting:
[GenericEntity:ServiceSemaphore][createdStamp,2019-09-19
16:47:44.678(java.sql.Timestamp)][createdTxStamp,2019-09-19
16:47:44.678(java.sql.Timestamp)][lastUpdatedStamp,2019-09-19
16:47:44.678(java.sql.Timestamp)][lastUpdatedTxStamp,2019-09-19
16:47:44.678(java.sql.Timestamp)][lockThread,OFBiz-JobQueue-2(java.lang.String)][lockTime,2019-09-19
16:47:44.676(java.sql.Timestamp)][lockedByInstanceId,emb-ofbiz-prd-technical-asg-20171209-01-eu-west-1b(java.lang.String)][serviceName,xxx(java.lang.String)]
(SQL Exception while executing the following:INSERT INTO
public.SERVICE_SEMAPHORE (SERVICE_NAME, LOCKED_BY_INSTANCE_ID, LOCK_THREAD,
LOCK_TIME, LAST_UPDATED_STAMP, LAST_UPDATED_TX_STAMP, CREATED_STAMP,
CREATED_TX_STAMP) VALUES (?, ?, ?, ?, ?, ?, ?, ?) (ERROR: duplicate key value
violates unique constraint "pk_service_semaphore" Detail: Key
(service_name)=(xxx) already exists.))) at
org.apache.ofbiz.entity.GenericDelegator.create(GenericDelegator.java:896)
~[ofbiz.jar:?] at
org.apache.ofbiz.entity.GenericValue.create(GenericValue.java:76)
~[ofbiz.jar:?] at
org.apache.ofbiz.service.semaphore.ServiceSemaphore.dbWrite(ServiceSemaphore.java:172)
[ofbiz.jar:?] at
org.apache.ofbiz.service.semaphore.ServiceSemaphore.checkLockNeedToWait(ServiceSemaphore.java:137)
[ofbiz.jar:?] at
org.apache.ofbiz.service.semaphore.ServiceSemaphore.acquire(ServiceSemaphore.java:70)
[ofbiz.jar:?] at
org.apache.ofbiz.service.ServiceDispatcher.runSync(ServiceDispatcher.java:284)
[ofbiz.jar:?] at
org.apache.ofbiz.service.ServiceDispatcher.runSync(ServiceDispatcher.java:240)
[ofbiz.jar:?] at
org.apache.ofbiz.service.GenericDispatcherFactory$GenericDispatcher.runSync(GenericDispatcherFactory.java:88)
[ofbiz.jar:?] at
org.apache.ofbiz.service.job.GenericServiceJob.exec(GenericServiceJob.java:70)
[ofbiz.jar:?] at
org.apache.ofbiz.service.job.AbstractJob.run(AbstractJob.java:87) [ofbiz.jar:?]
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[?:1.8.0_222] at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[?:1.8.0_222] at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222] |
{code}
With lot of activity this can spam the logs reducing visibility of real errors
in production logs.
For this, i proposed to add a last check within the synchronized method before
inserting the lock, on which the fk constraint error is thrown.
This avoiding the error, if no other method in OFBiz insert data in
`ServiceSemaphore` table...
A second patch is provided to add javadoc and trivial refoctoring
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
