LDAP sync fails after CleanAlfPropTablesPostExec.sql/CleanAlfPropTables.sql

[idwright]

My ldap sync is broken with the error message:

2019-08-10 03:16:18,271 ERROR [org.quartz.core.JobRunShell] [DefaultScheduler_Worker-3] Job DEFAULT.ldapPeopleJobDetail threw an unhandled Exception:
org.springframework.dao.DataIntegrityViolationException: No property value exists for ID 2927643
at org.alfresco.repo.domain.propval.AbstractPropertyValueDAOImpl.getPropertyById(AbstractPropertyValueDAOImpl.java:841)
at org.alfresco.repo.domain.propval.AbstractPropertyValueDAOImpl.getPropertyUniqueContext(AbstractPropertyValueDAOImpl.java:1293)
at org.alfresco.repo.attributes.AttributeServiceImpl.setAttribute(AttributeServiceImpl.java:175)

This is similar to the following:

Synchronization aborted due to error DataIntegrityViolationException: No property value exists for I... 

and

Unfortunately I didn't notice it at the time but looking at the logs this problem seemed to start here (multiple lines replaced with ... for clarity)

Any ideas on how to get this working again would be very welcome.

Thanks.

2019-08-10 03:00:00,614 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Executing database script /tmp/tomcat7-tomcat7-tmp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-1023817728131585085.sql (Copied from alfresco/dbscripts/utility/org.hibernate.dialect.MySQLInnoDBDialect/CleanAlfPropTablesPostExec.sql).
2019-08-10 03:00:00,675 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Executing database script /tmp/tomcat7-tomcat7-tmp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-7622424929137716558.sql (Copied from alfresco/dbscripts/utility/org.hibernate.dialect.MySQLInnoDBDialect/CleanAlfPropTables.sql).
2019-08-10 03:00:00,846 WARN [org.cggh.repo.security.sync.CustomChainingUserRegistrySynchronizer] [DefaultScheduler_Worker-2] Full synchronization with user registry 'ldap1'
2019-08-10 03:00:00,846 WARN [org.alfresco.repo.security.sync.CustomChainingUserRegistrySynchronizer] [DefaultScheduler_Worker-2] Some users and groups previously created by synchronization with this user registry may be removed.
2019-08-10 03:00:05,218 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 0 to 10000 rows of 1 rows from table alf_audit_app.
2019-08-10 03:00:05,769 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 0 to 1 rows of 0 rows from table alf_audit_entry.
2019-08-10 03:00:06,406 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 0 to 10000 rows of 2927637 rows from table alf_prop_unique_ctx.
...
2019-08-10 03:00:13,279 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 0 to 10000 rows of 2927637 rows from table alf_prop_root.
2019-08-10 03:00:13,292 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 10000 to 20000 rows of 2927637 rows from table alf_prop_root.
2019-08-10 03:00:13,313 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 20000 to 30000 rows of 2927637 rows from table alf_prop_root.
2019-08-10 03:00:13,347 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 30000 to 40000 rows of 2927637 rows from table alf_prop_root.
....
2019-08-10 03:00:18,666 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 2920000 to 2930000 rows of 2927637 rows from table alf_prop_root.
2019-08-10 03:00:18,786 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 0 to 10000 rows of 2927635 rows from table temp_prop_root_obs.
2019-08-10 03:00:18,788 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 10000 to 20000 rows of 2927635 rows from table temp_prop_root_obs.
2019-08-10 03:00:18,789 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 20000 to 30000 rows of 2927635 rows from table temp_prop_root_obs.
...
2019-08-10 03:00:19,299 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 2910000 to 2920000 rows of 2927635 rows from table temp_prop_root_obs.
2019-08-10 03:00:19,601 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 2920000 to 2930000 rows of 2927635 rows from table temp_prop_root_obs.
2019-08-10 03:00:20,838 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 0 to 10000 rows of 400333 rows from table alf_prop_value.
2019-08-10 03:00:20,862 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 10000 to 20000 rows of 400333 rows from table alf_prop_value.
...
2019-08-10 03:00:21,375 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 400000 to 410000 rows of 400333 rows from table alf_prop_value.
2019-08-10 03:00:21,388 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 0 to 1 rows of 0 rows from table alf_audit_entry.
2019-08-10 03:00:21,400 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 0 to 10000 rows of 400333 rows from table alf_prop_link.
...
2019-08-10 03:00:24,059 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 400000 to 410000 rows of 400333 rows from table alf_prop_link.
2019-08-10 03:00:24,076 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 0 to 10000 rows of 66986 rows from table alf_prop_unique_ctx.
2019-08-10 03:00:24,109 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 10000 to 20000 rows of 66986 rows from table alf_prop_unique_ctx.
2019-08-10 03:00:24,181 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 20000 to 30000 rows of 66986 rows from table alf_prop_unique_ctx.
...
019-08-10 03:00:26,525 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 390000 to 400000 rows of 398263 rows from table alf_prop_unique_ctx.
2019-08-10 03:00:26,546 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 0 to 10000 rows of 400333 rows from table alf_prop_value.
2019-08-10 03:00:26,561 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 10000 to 20000 rows of 400333 rows from table alf_prop_value.
2019-08-10 03:00:26,578 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 20000 to 30000 rows of 400333 rows from table alf_prop_value.
...
2019-08-10 03:00:27,291 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 400000 to 410000 rows of 400333 rows from table alf_prop_value.
2019-08-10 03:00:27,326 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 0 to 10000 rows of 400332 rows from table temp_prop_val_obs.
2019-08-10 03:00:27,331 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 10000 to 20000 rows of 400332 rows from table temp_prop_val_obs.
...
2019-08-10 03:00:28,368 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 400000 to 410000 rows of 400332 rows from table temp_prop_val_obs.
2019-08-10 03:00:28,383 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 0 to 10000 rows of 4224 rows from table temp_del_str1.
2019-08-10 03:00:28,401 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 0 to 10000 rows of 400332 rows from table temp_prop_val_obs.
2019-08-10 03:00:28,418 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 10000 to 20000 rows of 400332 rows from table temp_prop_val_obs.
...
2019-08-10 03:00:28,823 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 400000 to 410000 rows of 400332 rows from table temp_prop_val_obs.
2019-08-10 03:00:28,838 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 0 to 1 rows of 0 rows from table temp_del_ser1.
2019-08-10 03:00:28,842 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 0 to 10000 rows of 400332 rows from table temp_prop_val_obs.
2019-08-10 03:00:28,854 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 10000 to 20000 rows of 400332 rows from table temp_prop_val_obs.
...
2019-08-10 03:00:29,338 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 400000 to 410000 rows of 400332 rows from table temp_prop_val_obs.
2019-08-10 03:00:29,352 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Processing from 0 to 1 rows of 0 rows from table temp_del_double1.
2019-08-10 03:00:29,356 INFO [org.alfresco.repo.domain.schema.script.ScriptExecutorImpl] [DefaultScheduler_Worker-10] Executing database script /tmp/tomcat7-tomcat7-tmp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-4347848468998907419.sql (Copied from alfresco/dbscripts/utility/org.hibernate.dialect.MySQLInnoDBDialect/CleanAlfPropTablesPostExec.sql).
2019-08-10 03:16:18,271 ERROR [org.quartz.core.JobRunShell] [DefaultScheduler_Worker-3] Job DEFAULT.ldapPeopleJobDetail threw an unhandled Exception:
org.springframework.dao.DataIntegrityViolationException: No property value exists for ID 2927643
at org.alfresco.repo.domain.propval.AbstractPropertyValueDAOImpl.getPropertyById(AbstractPropertyValueDAOImpl.java:841)
at org.alfresco.repo.domain.propval.AbstractPropertyValueDAOImpl.getPropertyUniqueContext(AbstractPropertyValueDAOImpl.java:1293)
at org.alfresco.repo.attributes.AttributeServiceImpl.setAttribute(AttributeServiceImpl.java:175)

[angelborroy]

It looks like there are some properties missing in the database.

Try to remove them manually, something like this:

delete from alf_prop_unique_ctx where prop1_id = 2927643;

delete from alf_prop_root where id = 2927643;‍‍‍‍‍‍

[michaelzietlow]

Thanks you @angelborroy ,
Deleting the ID(s) from the db as you suggested cleared my errors... 

[yreg]

I have solved this a while back by executing a JS snippet in JS Console, I couldn't find the final one, but I found the initial draft which might work from the first try or might require some fine-tuning first. PLEASE TEST IT ON A NON CRUCIAL ENVIRONMENT FIRST.

var context = Packages.org.springframework.web.context.ContextLoader.getCurrentWebApplicationContext();
var SyncStatus = Packages.org.alfresco.repo.security.sync.SyncStatus;
var attributeService = context.getBean('attributeService', Packages.org.alfresco.service.cmr.attributes.AttributeService);
 
var ROOT_ATTRIBUTE_PATH = ".ChainingUserRegistrySynchronizer";
var STATUS_ATTRIBUTE = "STATUS";
 
logger.log(attributeService.getAttribute(ROOT_ATTRIBUTE_PATH, STATUS_ATTRIBUTE));
 
 
 
/* experimental stuff */
 
attributeService.removeAttribute(ROOT_ATTRIBUTE_PATH, STATUS_ATTRIBUTE);
 
attributeService.createAttribute(SyncStatus.COMPLETE_ERROR.toString() ,ROOT_ATTRIBUTE_PATH, STATUS_ATTRIBUTE);
 
logger.log(attributeService.getAttribute(ROOT_ATTRIBUTE_PATH, STATUS_ATTRIBUTE));‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

[afaust]

Please, always be aware that the in-memory caches of Alfresco can still contain some values (e.g. mapping String value x to ID y) which CleanAlfPropTables may delete. The whole prop_value code in Alfresco never checks if the cached entries still exist before (re-)linking and will throw up if they don't. Typically, a restart is required / advisable after running CleanAlfPropTables to ensure caches are clear, or you should manually clear the caches via the OOTBee Support Tools.

Problems like this had motivated me to write an improved cleanup process, which also includes clearing any old cache entries, so it is safe to run any synchronisation processes afterwards.

[idwright · Accepted solution]

Unfortunately not the caches.

The script from Younes REGAIEG‌ provided a good start but more than one property was involved. By using the stack trace, either from the logs or in the javascript console, I could look up the names of the relevant properties in the code using the line numbers. (Easiest way to see the full stack trace is to not catch the exception from getAttribute)

This should be safe to run as it only does something if an exception is thrown when trying to get an attribute.

You may need to change the value of zone to match your configuration.

var context = Packages.org.springframework.web.context.ContextLoader.getCurrentWebApplicationContext();
var SyncStatus = Packages.org.alfresco.repo.security.sync.SyncStatus;
var attributeService = context.getBean('attributeService', packages.org.alfresco.service.cmr.attributes.AttributeService);

var ROOT_ATTRIBUTE_PATH = ".ChainingUserRegistrySynchronizer";
var STATUS_ATTRIBUTE = "STATUS";
var SUMMARY_ATTRIBUTE = "SUMMARY";
var zone = "ldap1";

try {
    logger.log(attributeService.getAttribute(ROOT_ATTRIBUTE_PATH, STATUS_ATTRIBUTE));
} catch(excep) {
    logger.log("Missing attribute:" + ROOT_ATTRIBUTE_PATH + " " + STATUS_ATTRIBUTE + excep);
    attributeService.removeAttribute(ROOT_ATTRIBUTE_PATH, STATUS_ATTRIBUTE);
    attributeService.createAttribute(SyncStatus.COMPLETE_ERROR.toString() ,ROOT_ATTRIBUTE_PATH, STATUS_ATTRIBUTE);
    logger.log("Created attribute");
    logger.log(attributeService.getAttribute(ROOT_ATTRIBUTE_PATH, STATUS_ATTRIBUTE));
}

try {
    logger.log(attributeService.getAttribute(ROOT_ATTRIBUTE_PATH, STATUS_ATTRIBUTE, zone));
} catch(excep) {
    logger.log("Missing attribute:" + ROOT_ATTRIBUTE_PATH + " " + STATUS_ATTRIBUTE + " " + zone + excep);
    attributeService.removeAttribute(ROOT_ATTRIBUTE_PATH, STATUS_ATTRIBUTE, zone);
    attributeService.createAttribute(SyncStatus.COMPLETE_ERROR.toString() ,ROOT_ATTRIBUTE_PATH, STATUS_ATTRIBUTE, zone);
    logger.log("Created attribute");
    logger.log(attributeService.getAttribute(ROOT_ATTRIBUTE_PATH, STATUS_ATTRIBUTE, zone));
}

try {
    logger.log(attributeService.getAttribute(ROOT_ATTRIBUTE_PATH, SUMMARY_ATTRIBUTE, zone));
} catch(excep) {
    logger.log("Missing attribute:" + ROOT_ATTRIBUTE_PATH + " " + SUMMARY_ATTRIBUTE + " " + zone + excep);
    attributeService.removeAttribute(ROOT_ATTRIBUTE_PATH, SUMMARY_ATTRIBUTE, zone);
    logger.log("Removed attribute");
}

[heiko_robert]

Ian Wright‌, thanks for sharing your solution!
just a small typo: in line #3 "packages.org.alfresco..." should start with a upper case letter.

[ainsof]

Thanks so much. This script worked like magic. Had to run it twice for some reason but so happy it worked. Been looking for a fix for a few days. Saved me from restoring an old backup.

Seems the issue was triggered by an incomplete running of the "propTablesCleanupJobDetail" scheduled task

[shriyam_gupta]

Where and how did you run this cript can you provide with me with steps i am facing the same issue and trying to figure out the solution 

[shriyam_gupta]

I was able to fix this issue by manually updating the Id's to Null in table for coloumn prop1_id
found out the root cause of this issue was breaking of alfresco schedule job called PostpropCleanerDetail job
the system was unable to find any property values of ID's in prop1_id coloumn and was throwing the error, on putting it to null the alfresco created new prop1_id automatically and all the errors disappeared and ldap sync started working. Deleting these Id's works the same way.