AnsweredAssumed Answered

alfresco hits database continuously that lead to create massive database connections/access logs on database side.

Question asked by arif.aghariya on Mar 6, 2018

Hello All,

I am using alfresco community edition 5.2 , recently i have notice that alfresco continuously accessing database for multiple connection and also for some background jobs.due to that database level logs are getting increased in massive amount. 

Is there any way that we can reduce this to smaller amount or minimal access. 

 

here are logs i am getting.

 

 

2018-03-06 10:02:43 IST [12169]: [278-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.122 ms bind S_2: select
*
from
alf_lock_resource
where
qname_ns_id = $1 and
qname_localname = $2
2018-03-06 10:02:43 IST [12169]: [279-1] db=testdb,user=testdb_appuser,client=10.35.*.* DETAIL: parameters: $1 = '1', $2 = 'activitypostlookup'
2018-03-06 10:02:43 IST [12169]: [280-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: execute S_2: select
*
from
alf_lock_resource
where
qname_ns_id = $1 and
qname_localname = $2
2018-03-06 10:02:43 IST [12169]: [281-1] db=testdb,user=testdb_appuser,client=10.35.*.* DETAIL: parameters: $1 = '1', $2 = 'activitypostlookup'
2018-03-06 10:02:43 IST [12169]: [282-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.039 ms
2018-03-06 10:02:43 IST [12169]: [283-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.092 ms parse S_3: update
alf_lock
set
version = version + 1,
lock_token = $1,
start_time = $2,
expiry_time = $3
where
excl_resource_id = $4 and
lock_token = $5
2018-03-06 10:02:43 IST [12169]: [284-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.114 ms bind S_3: update
alf_lock
set
version = version + 1,
lock_token = $1,
start_time = $2,
expiry_time = $3
where
excl_resource_id = $4 and
lock_token = $5
2018-03-06 10:02:43 IST [12169]: [285-1] db=testdb,user=testdb_appuser,client=10.35.*.* DETAIL: parameters: $1 = 'not-locked', $2 = '0', $3 = '0', $4 = '7', $5 = '1efa2de3-5be8-4c24-88b3-acf7b009c89c'
2018-03-06 10:02:43 IST [12169]: [286-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: execute S_3: update
alf_lock
set
version = version + 1,
lock_token = $1,
start_time = $2,
expiry_time = $3
where
excl_resource_id = $4 and
lock_token = $5
2018-03-06 10:02:43 IST [12169]: [287-1] db=testdb,user=testdb_appuser,client=10.35.*.* DETAIL: parameters: $1 = 'not-locked', $2 = '0', $3 = '0', $4 = '7', $5 = '1efa2de3-5be8-4c24-88b3-acf7b009c89c'
2018-03-06 10:02:43 IST [12182]: [578-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.012 ms bind S_1: COMMIT
2018-03-06 10:02:43 IST [12182]: [579-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: execute S_1: COMMIT
2018-03-06 10:02:43 IST [12169]: [288-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.053 ms
2018-03-06 10:02:43 IST [12169]: [289-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.010 ms bind S_1: COMMIT
2018-03-06 10:02:43 IST [12169]: [290-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: execute S_1: COMMIT
2018-03-06 10:02:43 IST [12169]: [291-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.035 ms
2018-03-06 10:02:43 IST [12182]: [580-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 30.026 ms
2018-03-06 10:02:43 IST [12182]: [581-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.018 ms parse <unnamed>: BEGIN
2018-03-06 10:02:43 IST [12182]: [582-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.007 ms bind <unnamed>: BEGIN
2018-03-06 10:02:43 IST [12182]: [583-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: execute <unnamed>: BEGIN
2018-03-06 10:02:43 IST [12182]: [584-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.009 ms
2018-03-06 10:02:43 IST [12182]: [585-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.018 ms parse <unnamed>: SELECT 1
2018-03-06 10:02:43 IST [12182]: [586-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.020 ms bind <unnamed>: SELECT 1
2018-03-06 10:02:43 IST [12182]: [587-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: execute <unnamed>: SELECT 1
2018-03-06 10:02:43 IST [12182]: [588-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.012 ms
2018-03-06 10:02:43 IST [12182]: [589-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.089 ms parse <unnamed>: select
sequence_id as id,
activity_data as activityData,
activity_type as activityType,
post_user_id as userId,
post_date as postDate,
job_task_node as jobTaskNode,
site_network as siteNetwork,
app_tool as appTool,
status as status
from
alf_activity_post
where
status = $1
2018-03-06 10:02:43 IST [12182]: [590-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.097 ms bind <unnamed>: select
sequence_id as id,
activity_data as activityData,
activity_type as activityType,
post_user_id as userId,
post_date as postDate,
job_task_node as jobTaskNode,
site_network as siteNetwork,
app_tool as appTool,
status as status
from
alf_activity_post
where
status = $1
2018-03-06 10:02:43 IST [12182]: [591-1] db=testdb,user=testdb_appuser,client=10.35.*.* DETAIL: parameters: $1 = 'PENDING'
2018-03-06 10:02:43 IST [12182]: [592-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: execute <unnamed>: select
sequence_id as id,
activity_data as activityData,
activity_type as activityType,
post_user_id as userId,
post_date as postDate,
job_task_node as jobTaskNode,
site_network as siteNetwork,
app_tool as appTool,
status as status
from
alf_activity_post
where
status = $1
2018-03-06 10:02:43 IST [12182]: [593-1] db=testdb,user=testdb_appuser,client=10.35.*.* DETAIL: parameters: $1 = 'PENDING'
2018-03-06 10:02:43 IST [12182]: [594-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.030 ms
2018-03-06 10:02:43 IST [12182]: [595-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.015 ms bind S_1: COMMIT
2018-03-06 10:02:43 IST [12182]: [596-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: execute S_1: COMMIT
2018-03-06 10:02:43 IST [12182]: [597-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.031 ms
2018-03-06 10:02:43 IST [12182]: [598-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.028 ms parse <unnamed>: BEGIN
2018-03-06 10:02:43 IST [12182]: [599-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.015 ms bind <unnamed>: BEGIN
2018-03-06 10:02:43 IST [12182]: [600-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: execute <unnamed>: BEGIN
2018-03-06 10:02:43 IST [12182]: [601-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.017 ms
2018-03-06 10:02:43 IST [12182]: [602-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.031 ms parse <unnamed>: SELECT 1
2018-03-06 10:02:43 IST [12182]: [603-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.032 ms bind <unnamed>: SELECT 1
2018-03-06 10:02:43 IST [12182]: [604-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: execute <unnamed>: SELECT 1
2018-03-06 10:02:43 IST [12182]: [605-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.020 ms
2018-03-06 10:02:43 IST [12182]: [606-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.088 ms bind S_3: select
*
from
alf_lock_resource
where
qname_ns_id = $1 and
qname_localname = $2
2018-03-06 10:02:43 IST [12182]: [607-1] db=testdb,user=testdb_appuser,client=10.35.*.* DETAIL: parameters: $1 = '1', $2 = 'activitypostlookup'
2018-03-06 10:02:43 IST [12182]: [608-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: execute S_3: select
*
from
alf_lock_resource
where
qname_ns_id = $1 and
qname_localname = $2
2018-03-06 10:02:43 IST [12182]: [609-1] db=testdb,user=testdb_appuser,client=10.35.*.* DETAIL: parameters: $1 = '1', $2 = 'activitypostlookup'
2018-03-06 10:02:43 IST [12182]: [610-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.033 ms
2018-03-06 10:02:43 IST [12182]: [611-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.064 ms parse S_4: update
alf_lock
set
version = version + 1,
lock_token = $1,
start_time = $2,
expiry_time = $3
where
excl_resource_id = $4 and
lock_token = $5
2018-03-06 10:02:43 IST [12182]: [612-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.082 ms bind S_4: update
alf_lock
set
version = version + 1,
lock_token = $1,
start_time = $2,
expiry_time = $3
where
excl_resource_id = $4 and
lock_token = $5
2018-03-06 10:02:43 IST [12182]: [613-1] db=testdb,user=testdb_appuser,client=10.35.*.* DETAIL: parameters: $1 = 'not-locked', $2 = '0', $3 = '0', $4 = '7', $5 = '01dedca3-bfda-498a-86ad-eee775a0e3d0'
2018-03-06 10:02:43 IST [12182]: [614-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: execute S_4: update
alf_lock
set
version = version + 1,
lock_token = $1,
start_time = $2,
expiry_time = $3
where
excl_resource_id = $4 and
lock_token = $5
2018-03-06 10:02:43 IST [12182]: [615-1] db=testdb,user=testdb_appuser,client=10.35.*.* DETAIL: parameters: $1 = 'not-locked', $2 = '0', $3 = '0', $4 = '7', $5 = '01dedca3-bfda-498a-86ad-eee775a0e3d0'
2018-03-06 10:02:43 IST [12182]: [616-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.088 ms
2018-03-06 10:02:43 IST [12182]: [617-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.008 ms bind S_1: COMMIT
2018-03-06 10:02:43 IST [12182]: [618-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: execute S_1: COMMIT
2018-03-06 10:02:43 IST [12182]: [619-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 57.508 ms


018-03-06 10:04:02 IST [12169]: [362-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.041 ms bind <unnamed>: SELECT 1
2018-03-06 10:04:02 IST [12169]: [363-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: execute <unnamed>: SELECT 1
2018-03-06 10:04:02 IST [12169]: [364-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.020 ms
2018-03-06 10:04:02 IST [12169]: [365-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.234 ms parse <unnamed>: select
RES.*
from ACT_RU_JOB RES
LEFT OUTER JOIN ACT_RU_EXECUTION PI ON PI.ID_ = RES.PROCESS_INSTANCE_ID_
where (RES.RETRIES_ > 0)
and (RES.DUEDATE_ is null or RES.DUEDATE_ <= $1)
and (RES.LOCK_OWNER_ is null or RES.LOCK_EXP_TIME_ <= $2)
and (
(RES.EXECUTION_ID_ is null)
or
(PI.SUSPENSION_STATE_ = 1)
)
LIMIT $3 OFFSET $4
2018-03-06 10:04:02 IST [12169]: [366-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.503 ms bind <unnamed>: select
RES.*
from ACT_RU_JOB RES
LEFT OUTER JOIN ACT_RU_EXECUTION PI ON PI.ID_ = RES.PROCESS_INSTANCE_ID_
where (RES.RETRIES_ > 0)
and (RES.DUEDATE_ is null or RES.DUEDATE_ <= $1)
and (RES.LOCK_OWNER_ is null or RES.LOCK_EXP_TIME_ <= $2)
and (
(RES.EXECUTION_ID_ is null)
or
(PI.SUSPENSION_STATE_ = 1)
)
LIMIT $3 OFFSET $4
2018-03-06 10:04:02 IST [12169]: [367-1] db=testdb,user=testdb_appuser,client=10.35.*.* DETAIL: parameters: $1 = '2018-03-06 10:01:04.065', $2 = '2018-03-06 10:01:04.065', $3 = '1', $4 = '0'
2018-03-06 10:04:02 IST [12169]: [368-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: execute <unnamed>: select
RES.*
from ACT_RU_JOB RES
LEFT OUTER JOIN ACT_RU_EXECUTION PI ON PI.ID_ = RES.PROCESS_INSTANCE_ID_
where (RES.RETRIES_ > 0)
and (RES.DUEDATE_ is null or RES.DUEDATE_ <= $1)
and (RES.LOCK_OWNER_ is null or RES.LOCK_EXP_TIME_ <= $2)
and (
(RES.EXECUTION_ID_ is null)
or
(PI.SUSPENSION_STATE_ = 1)
)
LIMIT $3 OFFSET $4
2018-03-06 10:04:02 IST [12169]: [369-1] db=testdb,user=testdb_appuser,client=10.35.*.* DETAIL: parameters: $1 = '2018-03-06 10:01:04.065', $2 = '2018-03-06 10:01:04.065', $3 = '1', $4 = '0'
2018-03-06 10:04:02 IST [12169]: [370-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.040 ms
2018-03-06 10:04:02 IST [12169]: [371-1] db=testdb,user=testdb_appuser,client=10.35.*.* LOG: duration: 0.044 ms bind S_1: COMMIT

 

Outcomes