topic Re: Recurring log entries every 15 seconds! in Alfresco Forum

Recurring log entries every 15 seconds!

ibar78 — Tue, 21 Mar 2017 15:16:25 GMT

Hi All,Wondering if someone can help explain what the following log entry means and what I can do to stop it:2017-03-21 14:54:30,009 INFO [org.alfresco.repo.transaction.RetryingTransactionHelper] [DefaultScheduler_Worker-9] Retrying DefaultScheduler_Worker-9: count 0; wait: 0.0s; msg: "Incorrect n

Re: Recurring log entries every 15 seconds!

ibar78 — Tue, 21 Mar 2017 16:39:12 GMT

I have set logging to debug mode in the hope it will provide more information to the problem. So I get the following entry every 15 seconds:

2017-03-21 16:35:15,025 DEBUG [org.alfresco.repo.transaction.RetryingTransactionHelper] [DefaultScheduler_Worker-9]
Transaction commit failed:
   Thread: DefaultScheduler_Worker-9
   Txn:    UserTransaction[object=org.alfresco.util.transaction.SpringAwareUserTransaction@52d706d1, status=0]
   Iteration: 0
   Exception follows:
org.alfresco.repo.lock.LockAcquisitionException: 02210019 Failed to get lock '{http://www.alfresco.org/model/system/1.0}activitypostlookup' using token 'ffd181b4-5c34-4738-b8d3-1ba52663cdde'.
   at org.alfresco.repo.domain.locks.AbstractLockDAOImpl.getLock(AbstractLockDAOImpl.java:137)
   at org.alfresco.repo.lock.JobLockServiceImpl$5.execute(JobLockServiceImpl.java:466)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:457)
   at org.alfresco.repo.lock.JobLockServiceImpl.doWithRetry(JobLockServiceImpl.java:518)
   at org.alfresco.repo.lock.JobLockServiceImpl.getLockImpl(JobLockServiceImpl.java:472)
   at org.alfresco.repo.lock.JobLockServiceImpl.getLock(JobLockServiceImpl.java:222)
   at org.alfresco.repo.lock.JobLockServiceImpl.getLock(JobLockServiceImpl.java:212)
   at org.alfresco.repo.activities.post.lookup.PostLookup.acquireLock(PostLookup.java:789)
   at org.alfresco.repo.activities.post.lookup.PostLookup.execute(PostLookup.java:203)
   at org.alfresco.repo.activities.post.lookup.PostLookupJob.execute(PostLookupJob.java:50)
   at org.quartz.core.JobRunShell.run(JobRunShell.java:216)
   at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:563)
Caused by: org.springframework.dao.ConcurrencyFailureException: Incorrect number of rows affected for updateLock: LockEntity[ ID=15, sharedResourceId=14, exclusiveResourceId=14]: expected 1, actual 0
   at org.alfresco.repo.domain.locks.ibatis.LockDAOImpl.updateLock(LockDAOImpl.java:150)
   at org.alfresco.repo.domain.locks.AbstractLockDAOImpl.getLock(AbstractLockDAOImpl.java:133)
   ... 11 more

Can anyone help me explain what this means please?

Re: Recurring log entries every 15 seconds!

afaust — Tue, 21 Mar 2017 23:24:33 GMT

That is a message from a scheduled job that is triggered in regular intervals. Since you are referring to an Alfresco Enterprise version you may be running Alfresco in a cluster / on multiple machines against the same database. In that case there can be instances where both servers try to run the job at the same time and only one can get the lock to ensure only one runs at the same time.

Re: Recurring log entries every 15 seconds!

ibar78 — Wed, 22 Mar 2017 09:20:14 GMT

That's correct we have 2 Alfresco servers running in a cluster against a Postgres database server so that makes sense. Is this normal behaviour? How do i determine what these jobs are and is it possible to change the schedule or is this something that is fixed within Alfresco and cannot be changed?

Many thanks for your help!

Re: Recurring log entries every 15 seconds!

afaust — Wed, 22 Mar 2017 12:03:19 GMT

Since this is a DEBUG message it is something that Alfresco already expects can happen. If you don't set the log level to DEBUG you won't even notice it is happening underneath the covers in the first place.