Hi all,I have a problem upgrading Alfresco 3.0 to Alfresco 3.3. From the log I can see that PathExecuter is looping in his attemps to to migrate old-style content URL storage to the newer alf_content_url storage, as I can understand from ContentUrlConverterPatch that is the class that log it. It reach about 36500 URLs and then it start from the beginning again, and again:
…
14:35:24,437 User:System INFO [admin.patch.PatchExecuter] Processed 36,500 content URLs from store.
14:39:23,399 User:System INFO [admin.patch.PatchExecuter] Processed 500 content URLs from store.
…
I have about 26GB of data in my contentstore directory, so I think it can be some problem related to the huge load of data to read. I'm using Postgres 8 as database. Or it can be one corrupted node?Any help is higly appreciated!
Another secondary problem is that I noticed that this upgrade was working also in the binary data in the contentstore. In particular some binary file are missing from the contentstore after the upgrade, does anyone know why and where these files are gone???Complete Stacktrace:
CompilerOracle: exclude org/apache/lucene/index/IndexReader$1.doBody
CompilerOracle: exclude org/alfresco/repo/search/impl/lucene/index/IndexInfo$Merger.mergeIndexes
CompilerOracle: exclude org/alfresco/repo/search/impl/lucene/index/IndexInfo$Merger.mergeDeletions
May 12, 2010 1:25:01 PM org.apache.catalina.core.AprLifecycleListener init
INFO: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: /usr/local/jdk1.6.0_14/jre/lib/amd64/server:/usr/local/jdk1.6.0_14/jre/lib/amd64:/usr/local/jdk1.6.0_14/jre/../lib/amd64:/usr/java/packages/lib/amd64:/lib:/usr/lib
May 12, 2010 1:25:02 PM org.apache.coyote.http11.Http11Protocol init
INFO: Initializing Coyote HTTP/1.1 on http-48080
May 12, 2010 1:25:02 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 327 ms
May 12, 2010 1:25:02 PM org.apache.catalina.core.StandardService start
INFO: Starting service Catalina
May 12, 2010 1:25:02 PM org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/6.0.18
May 12, 2010 1:25:02 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive alfresco.war
May 12, 2010 1:25:04 PM org.apache.catalina.core.StandardContext addApplicationListener
INFO: The listener "org.apache.myfaces.webapp.StartupServletContextListener" is already configured for this context. The duplicate definition has been ignored.
13:25:07,805 INFO [alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/repository.properties]
13:25:07,807 INFO [alfresco.config.JndiPropertiesFactoryBean] Loading properties file from class path resource [alfresco/domain/transaction.properties]
13:25:07,807 INFO [alfresco.config.JndiPropertiesFactoryBean] Loading properties file from URL [file:/opt/tomcat_alfresco/shared/classes/alfresco-global.properties]
13:25:07,888 INFO [alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
13:25:17,521 INFO [extensions.webscripts.TemplateProcessorRegistry] Registered template processor Repository Template Processor for extension ftl
13:25:17,523 INFO [extensions.webscripts.ScriptProcessorRegistry] Registered script processor Repository Script Processor for extension js
13:25:21,215 INFO [domain.schema.SchemaBootstrap] Schema managed by database dialect org.hibernate.dialect.PostgreSQLDialect.
13:25:24,481 INFO [domain.schema.SchemaBootstrap] Executing database script /opt/tomcat_alfresco/temp/Alfresco/AlfrescoSchema-PostgreSQLDialect-Update-264249785107181616.sql (Copied from classpath:alfresco/dbscripts/upgrade/2.2/org.hibernate.dialect.PostgreSQLDialect/AlfrescoSchemaUpdate-Person.sql).
13:26:11,051 INFO [domain.schema.SchemaBootstrap] Executing database script /opt/tomcat_alfresco/temp/Alfresco/AlfrescoSchema-PostgreSQLDialect-Update-5401172435411804623.sql (Copied from classpath:alfresco/dbscripts/create/3.2/org.hibernate.dialect.PostgreSQLDialect/AlfrescoPostCreate-3.2-LockTables.sql).
13:26:11,479 INFO [domain.schema.SchemaBootstrap] Executing database script /opt/tomcat_alfresco/temp/Alfresco/AlfrescoSchema-PostgreSQLDialect-Update-8674602557853885597.sql (Copied from classpath:alfresco/dbscripts/create/3.2/org.hibernate.dialect.PostgreSQLDialect/AlfrescoPostCreate-3.2-ContentTables.sql).
13:26:12,134 INFO [domain.schema.SchemaBootstrap] Executing database script /opt/tomcat_alfresco/temp/Alfresco/AlfrescoSchema-PostgreSQLDialect-Update-8699343042461007895.sql (Copied from classpath:alfresco/dbscripts/upgrade/3.2/org.hibernate.dialect.PostgreSQLDialect/AlfrescoSchemaUpdate-3.2-ContentTables2.sql).
13:26:12,222 INFO [domain.schema.SchemaBootstrap] Executing database script /opt/tomcat_alfresco/temp/Alfresco/AlfrescoSchema-PostgreSQLDialect-Update-396215000211409638.sql (Copied from classpath:alfresco/dbscripts/create/3.2/org.hibernate.dialect.PostgreSQLDialect/AlfrescoPostCreate-3.2-PropertyValueTables.sql).
13:26:13,284 INFO [domain.schema.SchemaBootstrap] Executing database script /opt/tomcat_alfresco/temp/Alfresco/AlfrescoSchema-PostgreSQLDialect-Update-5724595892061705517.sql (Copied from classpath:alfresco/dbscripts/create/3.2/org.hibernate.dialect.PostgreSQLDialect/AlfrescoPostCreate-3.2-AuditTables.sql).
13:26:13,707 INFO [domain.schema.SchemaBootstrap] Executing database script /opt/tomcat_alfresco/temp/Alfresco/AlfrescoSchema-PostgreSQLDialect-Update-2273017622511937801.sql (Copied from classpath:alfresco/dbscripts/upgrade/3.2/org.hibernate.dialect.PostgreSQLDialect/child-assoc-qname-crc.sql).
13:26:29,729 INFO [domain.schema.SchemaBootstrap] Executing database script /opt/tomcat_alfresco/temp/Alfresco/AlfrescoSchema-PostgreSQLDialect-Update-980226137431825728.sql (Generated).
13:26:29,789 INFO [domain.schema.SchemaBootstrap] Executing database script /opt/tomcat_alfresco/temp/Alfresco/AlfrescoSchema-PostgreSQLDialect-Update-2047456910438062439.sql (Copied from classpath:alfresco/dbscripts/upgrade/3.1/org.hibernate.dialect.PostgreSQLDialect/IPv6-patch.sql).
13:26:30,115 INFO [domain.schema.SchemaBootstrap] Executing database script /opt/tomcat_alfresco/temp/Alfresco/AlfrescoSchema-PostgreSQLDialect-Update-4611781391991990040.sql (Copied from classpath:alfresco/dbscripts/upgrade/3.2/org.hibernate.dialect.PostgreSQLDialect/remove-AVM-issuer.sql).
13:26:30,257 INFO [domain.schema.SchemaBootstrap] Executing database script /opt/tomcat_alfresco/temp/Alfresco/AlfrescoSchema-PostgreSQLDialect-Update-3340069529909858782.sql (Copied from classpath:alfresco/dbscripts/upgrade/3.2/org.hibernate.dialect.PostgreSQLDialect/modify-AVM-mimetype.sql).
13:26:30,782 INFO [domain.schema.SchemaBootstrap] Executing database script /opt/tomcat_alfresco/temp/Alfresco/AlfrescoSchema-PostgreSQLDialect-Update-2052506887475954118.sql (Copied from classpath:alfresco/dbscripts/upgrade/3.2/org.hibernate.dialect.PostgreSQLDialect/jbpm-upgrade.sql).
13:26:33,195 INFO [domain.schema.SchemaBootstrap] Executing database script /opt/tomcat_alfresco/temp/Alfresco/AlfrescoSchema-PostgreSQLDialect-Update-4014227950531214385.sql (Copied from classpath:alfresco/dbscripts/upgrade/3.3/org.hibernate.dialect.PostgreSQLDialect/remove-VersionCount.sql).
13:26:33,227 INFO [domain.schema.SchemaBootstrap] Executing database script /opt/tomcat_alfresco/temp/Alfresco/AlfrescoSchema-PostgreSQLDialect-Update-5846534134640375827.sql (Copied from classpath:alfresco/dbscripts/upgrade/3.3/org.hibernate.dialect.PostgreSQLDialect/fix-Repo-seqs_1.sql).
13:26:33,257 INFO [domain.schema.SchemaBootstrap] All executed statements: /opt/tomcat_alfresco/temp/Alfresco/AlfrescoSchema-PostgreSQLDialect-All_Statements-4600111225814754286.sql.
13:26:37,108 INFO [domain.schema.SchemaBootstrap] Normalized schema (pre-bootstrap) dumped to file /opt/tomcat_alfresco/temp/Alfresco/AlfrescoSchema-PostgreSQLDialect-6196099261868001939-Startup.xml.
13:26:37,108 INFO [domain.schema.SchemaBootstrap] Normalized schema (post-bootstrap) dumped to file /opt/tomcat_alfresco/temp/Alfresco/AlfrescoSchema-PostgreSQLDialect-7475217159011929042.xml.
13:26:37,113 INFO [management.subsystems.ChildApplicationContextFactory] Starting 'sysAdmin' subsystem, ID: [sysAdmin, default]
13:26:37,125 INFO [alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
13:26:37,136 INFO [management.subsystems.ChildApplicationContextFactory] Startup of 'sysAdmin' subsystem, ID: [sysAdmin, default] complete
13:26:38,294 INFO [management.subsystems.ChildApplicationContextFactory] Starting 'thirdparty' subsystem, ID: [thirdparty, default]
13:26:38,306 INFO [alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
13:26:38,399 ERROR [transform.magick.AbstractImageMagickContentTransformerWorker] ImageMagickContentTransformerWorker not available: 04120000 Failed to perform ImageMagick transformation:
Execution result:
os: Linux
command: [./ImageMagick/bin/convert, /opt/tomcat_alfresco/temp/Alfresco/ImageMagickContentTransformerWorker_init_source_2397814026615326945.gif[0], /opt/tomcat_alfresco/temp/Alfresco/ImageMagickContentTransformerWorker_init_target_8570898305538075100.png]
succeeded: false
exit code: 1
out:
err: Cannot run program "./ImageMagick/bin/convert": java.io.IOException: error=2, No such file or directory
13:26:38,486 ERROR [content.transform.RuntimeExecutableContentTransformerWorker] Failed to start a runtime executable content transformer:
Execution result:
os: Linux
command: [./bin/pdf2swf, -V]
succeeded: false
exit code: 1
out:
err: Cannot run program "./bin/pdf2swf": java.io.IOException: error=2, No such file or directory
13:26:38,492 INFO [management.subsystems.ChildApplicationContextFactory] Startup of 'thirdparty' subsystem, ID: [thirdparty, default] complete
13:26:38,492 INFO [management.subsystems.ChildApplicationContextFactory] Starting 'OOoDirect' subsystem, ID: [OOoDirect, default]
13:26:38,505 INFO [alfresco.config.JndiPropertyPlaceholderConfigurer] Loading properties file from class path resource [alfresco/alfresco-shared.properties]
13:26:38,746 ERROR [util.exec.RuntimeExecBootstrapBean] Bootstrap command failed:
Execution result:
os: Linux
command: [soffice, -accept=socket,host=localhost,port=8100;urp;StarOffice.ServiceManager, -env:UserInstallation=file:///opt/alfresco_api/alf_data/oouser, -nologo, -headless, -nofirststartwizard, -nocrashrep, -norestore]
succeeded: false
exit code: 2
out:
err: Cannot run program "soffice": java.io.IOException: error=2, No such file or directory
13:26:38,792 WARN [alfresco.util.OpenOfficeConnectionTester] An initial OpenOffice connection could not be established.
13:26:38,801 INFO [management.subsystems.ChildApplicationContextFactory] Startup of 'OOoDirect' subsystem, ID: [OOoDirect, default] complete
13:26:39,552 INFO [node.index.FullIndexRecoveryComponent] Index recovery started: 132,816 transactions.
### Excluding compile: org.alfresco.repo.search.impl.lucene.index.IndexInfo$Merger::mergeDeletions
13:28:06,970 INFO [node.index.FullIndexRecoveryComponent] 10 % complete.
13:29:15,491 INFO [node.index.FullIndexRecoveryComponent] 20 % complete.
13:30:18,824 INFO [node.index.FullIndexRecoveryComponent] 30 % complete.
13:32:01,676 INFO [node.index.FullIndexRecoveryComponent] 40 % complete.
13:33:39,264 INFO [node.index.FullIndexRecoveryComponent] 50 % complete.
13:35:08,419 INFO [node.index.FullIndexRecoveryComponent] 60 % complete.
13:36:36,264 INFO [node.index.FullIndexRecoveryComponent] 70 % complete.
13:38:06,321 INFO [node.index.FullIndexRecoveryComponent] 80 % complete.
13:39:33,028 INFO [node.index.FullIndexRecoveryComponent] 90 % complete.
13:43:29,323 INFO [node.index.FullIndexRecoveryComponent] 100 % complete.
13:47:34,597 INFO [node.index.FullIndexRecoveryComponent] Index recovery completed.
13:47:34,709 WARN [node.index.AVMFullIndexRecoveryComponent] Index for avm store sitestore is out of date
13:47:34,709 INFO [node.index.AVMFullIndexRecoveryComponent] Rebuilding indexes for 1 AVM Stores
13:47:34,709 INFO [node.index.AVMFullIndexRecoveryComponent] Auto recovering index for sitestore
13:47:34,717 INFO [node.index.AVMFullIndexRecoveryComponent] Reindex 100% complete
13:47:34,717 INFO [node.index.AVMFullIndexRecoveryComponent] Finished rebuilding indexes for AVM Stores
13:47:35,402 INFO [repo.admin.ConfigurationChecker] The Alfresco root data directory ('dir.root') is: /opt/alfresco_api/alf_data
13:47:35,673 INFO [admin.patch.PatchExecuter] Checking for patches to apply …
13:47:35,767 INFO [admin.patch.PatchExecuter] Applying patch 'patch.fixNameCrcValues-2' (Fixes name and qname CRC32 values to match UTF-8 encoding.).
13:47:48,433 User:System INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Commencing batch of 204957 entries
13:47:50,035 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 1000 entries out of 204957. 0% complete. Rate: 624 per second. 0 failures detected.
13:47:51,170 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 2000 entries out of 204957. 1% complete. Rate: 730 per second. 0 failures detected.
13:47:52,337 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 3000 entries out of 204957. 1% complete. Rate: 768 per second. 0 failures detected.
13:47:53,400 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 4000 entries out of 204957. 2% complete. Rate: 805 per second. 0 failures detected.
13:47:54,545 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 5000 entries out of 204957. 2% complete. Rate: 818 per second. 0 failures detected.
13:47:55,510 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 6000 entries out of 204957. 3% complete. Rate: 847 per second. 0 failures detected.
13:47:56,388 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 7000 entries out of 204957. 3% complete. Rate: 879 per second. 0 failures detected.
13:47:57,729 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 8000 entries out of 204957. 4% complete. Rate: 860 per second. 0 failures detected.
13:47:58,712 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 9000 entries out of 204957. 4% complete. Rate: 875 per second. 0 failures detected.
13:47:59,598 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 10000 entries out of 204957. 5% complete. Rate: 895 per second. 0 failures detected.
…
13:57:20,072 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 193000 entries out of 204957. 94% complete. Rate: 337 per second. 0 failures detected.
13:57:23,074 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 194000 entries out of 204957. 95% complete. Rate: 337 per second. 0 failures detected.
13:57:25,265 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 195000 entries out of 204957. 95% complete. Rate: 338 per second. 0 failures detected.
13:57:29,029 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 196000 entries out of 204957. 96% complete. Rate: 337 per second. 0 failures detected.
13:57:31,502 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 197000 entries out of 204957. 96% complete. Rate: 337 per second. 0 failures detected.
13:57:36,376 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 198000 entries out of 204957. 97% complete. Rate: 336 per second. 0 failures detected.
13:57:38,858 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 199000 entries out of 204957. 97% complete. Rate: 337 per second. 0 failures detected.
13:57:41,409 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 200000 entries out of 204957. 98% complete. Rate: 337 per second. 0 failures detected.
13:57:44,428 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 201000 entries out of 204957. 98% complete. Rate: 337 per second. 0 failures detected.
13:57:47,414 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 202000 entries out of 204957. 99% complete. Rate: 337 per second. 0 failures detected.
13:57:49,858 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 203000 entries out of 204957. 99% complete. Rate: 337 per second. 0 failures detected.
13:57:53,116 INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 204000 entries out of 204957. 100% complete. Rate: 337 per second. 0 failures detected.
13:57:55,901 User:System INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Processed 204957 entries out of 204957. 100% complete. Rate: 337 per second. 0 failures detected.
13:57:55,901 User:System INFO [patch.impl.FixNameCrcValuesPatch$HibernateHelper] FixNameCrcValuesPatch: Completed batch of 204957 entries
13:57:56,022 INFO [admin.patch.PatchExecuter] Applying patch 'patch.zonedAuthorities' (Adds the remodelled cm:authority container to the spaces store).
13:57:56,563 INFO [admin.patch.PatchExecuter] Applying patch 'patch.redeploySubmitProcess5' (Re-deploy WCM Submit Process Definition.).
13:57:56,796 INFO [admin.patch.PatchExecuter] Applying patch 'patch.deploySubmitDirectProcess' (Deploy WCM Direct Submit Process Definition.).
13:57:56,891 INFO [admin.patch.PatchExecuter] Applying patch 'patch.resetWCMToGroupBasedPermissionsPatch' (Reset WCM to group based permissions.).
13:57:56,893 User:System INFO [patch.impl.ResetWCMToGroupBasedPermissionsPatch] Retrieved list of 1 AVM store descriptors in 0 secs
13:57:56,895 User:System INFO [patch.impl.ResetWCMToGroupBasedPermissionsPatch] Retrieved store types for 0 WCM stores in 0 secs
13:57:56,902 INFO [admin.patch.PatchExecuter] Applying patch 'patch.moveWCMToGroupBasedPermissionsPatch' (A placeholder patch; usually marks a superceded patch.).
13:57:56,911 INFO [admin.patch.PatchExecuter] Applying patch 'patch.wcmPostPermissionSnapshotPatch3' (Snapshot stores (after fixing ACLs so they are only set on the staging area store).).
13:57:57,162 INFO [admin.patch.PatchExecuter] Applying patch 'patch.wcmPostPermissionSnapshotPatch2' (A placeholder patch; usually marks a superceded patch.).
13:57:57,166 INFO [admin.patch.PatchExecuter] Applying patch 'patch.redeploySubmitProcess6' (Re-deploy WCM Submit Process Definition.).
13:57:57,475 INFO [admin.patch.PatchExecuter] Applying patch 'patch.redeploySubmitProcess7' (Re-deploy WCM Submit Process Definition.).
13:57:57,764 INFO [admin.patch.PatchExecuter] Applying patch 'patch.webSiteAddModerated' (Changing Web Site visibility from a boolean to enum.).
13:57:57,795 INFO [admin.patch.PatchExecuter] Applying patch 'patch.invitationMigration' (Migrate invitations from old invite service to invitation service).
13:57:57,823 INFO [admin.patch.PatchExecuter] Applying patch 'patch.mtShareExistingTenants' (Update existing tenants for MT Share.).
13:57:57,826 INFO [admin.patch.PatchExecuter] Applying patch 'patch.redeployInvitationProcess' (Re-deploy Invitation Process Definitions.).
13:57:57,982 INFO [admin.patch.PatchExecuter] Applying patch 'patch.authorityMigration' (Copies any old authorities from the user store to the spaces store.).
13:58:10,676 User:System INFO [admin.patch.PatchExecuter] Authority Migration: Commencing batch of 17109 entries
13:58:12,705 INFO [admin.patch.PatchExecuter] Authority Migration: Processed 100 entries out of 17109. 1% complete. Rate: 49 per second. 0 failures detected.
13:58:13,975 INFO [admin.patch.PatchExecuter] Authority Migration: Processed 200 entries out of 17109. 1% complete. Rate: 60 per second. 0 failures detected.
13:58:15,289 INFO [admin.patch.PatchExecuter] Authority Migration: Processed 300 entries out of 17109. 2% complete. Rate: 65 per second. 0 failures detected.
13:58:16,887 INFO [admin.patch.PatchExecuter] Authority Migration: Processed 400 entries out of 17109. 2% complete. Rate: 64 per second. 0 failures detected.
13:58:18,156 INFO [admin.patch.PatchExecuter] Authority Migration: Processed 500 entries out of 17109. 3% complete. Rate: 66 per second. 0 failures detected.
13:58:19,684 INFO [admin.patch.PatchExecuter] Authority Migration: Processed 600 entries out of 17109. 4% complete. Rate: 66 per second. 0 failures detected.
13:58:21,289 INFO [admin.patch.PatchExecuter] Authority Migration: Processed 700 entries out of 17109. 4% complete. Rate: 65 per second. 0 failures detected.
13:58:22,470 INFO [admin.patch.PatchExecuter] Authority Migration: Processed 800 entries out of 17109. 5% complete. Rate: 67 per second. 0 failures detected.
…
14:03:44,723 WARN [org.alfresco.authorityTransactionalCache] Transactional update cache 'org.alfresco.authorityTransactionalCache' is full (100).
14:03:45,195 INFO [admin.patch.PatchExecuter] Authority Migration: Processed 16200 entries out of 17109. 95% complete. Rate: 48 per second. 0 failures detected.
14:03:48,117 INFO [admin.patch.PatchExecuter] Authority Migration: Processed 16300 entries out of 17109. 95% complete. Rate: 48 per second. 0 failures detected.
14:03:48,330 WARN [org.alfresco.authorityTransactionalCache] Transactional update cache 'org.alfresco.authorityTransactionalCache' is full (100).
14:03:50,973 INFO [admin.patch.PatchExecuter] Authority Migration: Processed 16400 entries out of 17109. 96% complete. Rate: 48 per second. 0 failures detected.
14:03:52,476 INFO [admin.patch.PatchExecuter] Authority Migration: Processed 16500 entries out of 17109. 96% complete. Rate: 48 per second. 0 failures detected.
14:03:52,982 WARN [org.alfresco.authorityTransactionalCache] Transactional update cache 'org.alfresco.authorityTransactionalCache' is full (100).
14:03:55,834 INFO [admin.patch.PatchExecuter] Authority Migration: Processed 16600 entries out of 17109. 97% complete. Rate: 48 per second. 0 failures detected.
14:03:55,936 WARN [org.alfresco.authorityTransactionalCache] Transactional update cache 'org.alfresco.authorityTransactionalCache' is full (100).
14:03:58,965 INFO [admin.patch.PatchExecuter] Authority Migration: Processed 16700 entries out of 17109. 98% complete. Rate: 47 per second. 0 failures detected.
14:04:02,661 WARN [org.alfresco.authorityTransactionalCache] Transactional update cache 'org.alfresco.authorityTransactionalCache' is full (100).
14:04:04,275 INFO [admin.patch.PatchExecuter] Authority Migration: Processed 16800 entries out of 17109. 98% complete. Rate: 47 per second. 0 failures detected.
14:04:04,376 WARN [org.alfresco.authorityTransactionalCache] Transactional update cache 'org.alfresco.authorityTransactionalCache' is full (100).
14:04:05,738 WARN [org.alfresco.authorityTransactionalCache] Transactional update cache 'org.alfresco.authorityTransactionalCache' is full (100).
14:04:07,139 INFO [admin.patch.PatchExecuter] Authority Migration: Processed 16900 entries out of 17109. 99% complete. Rate: 47 per second. 0 failures detected.
14:04:08,861 INFO [admin.patch.PatchExecuter] Authority Migration: Processed 17000 entries out of 17109. 99% complete. Rate: 47 per second. 0 failures detected.
14:04:09,106 WARN [org.alfresco.authorityTransactionalCache] Transactional update cache 'org.alfresco.authorityTransactionalCache' is full (100).
14:04:09,743 WARN [org.alfresco.authorityTransactionalCache] Transactional update cache 'org.alfresco.authorityTransactionalCache' is full (100).
14:04:18,458 INFO [admin.patch.PatchExecuter] Authority Migration: Processed 17100 entries out of 17109. 100% complete. Rate: 46 per second. 0 failures detected.
14:04:18,458 User:System INFO [admin.patch.PatchExecuter] Authority Migration: Processed 17109 entries out of 17109. 100% complete. Rate: 46 per second. 0 failures detected.
14:04:18,458 User:System INFO [admin.patch.PatchExecuter] Authority Migration: Completed batch of 17109 entries
14:04:18,543 INFO [admin.patch.PatchExecuter] Applying patch 'patch.authorityDefaultZonesPatch' (Adds groups and people to the appropriate zones for wcm, share and everything else.).
14:04:24,991 User:System INFO [admin.patch.PatchExecuter] Adding users to zones …
14:04:44,844 User:System WARN [org.alfresco.personTransactionalCache] Transactional update cache 'org.alfresco.personTransactionalCache' is full (1000).
14:04:57,167 User:System INFO [admin.patch.PatchExecuter] Patch patch.authorityDefaultZonesPatch 10% complete, estimated complete at 5/12/10 2:10 PM.
14:05:27,542 User:System INFO [admin.patch.PatchExecuter] Patch patch.authorityDefaultZonesPatch 20% complete, estimated complete at 5/12/10 2:10 PM.
14:05:58,132 User:System INFO [admin.patch.PatchExecuter] Patch patch.authorityDefaultZonesPatch 30% complete, estimated complete at 5/12/10 2:09 PM.
14:06:27,646 User:System INFO [admin.patch.PatchExecuter] Patch patch.authorityDefaultZonesPatch 40% complete, estimated complete at 5/12/10 2:09 PM.
14:06:38,513 User:System INFO [admin.patch.PatchExecuter] Adding groups to zones …
14:06:41,118 User:System WARN [org.alfresco.authorityTransactionalCache] Transactional update cache 'org.alfresco.authorityTransactionalCache' is full (100).
14:06:52,158 User:System INFO [admin.patch.PatchExecuter] Patch patch.authorityDefaultZonesPatch 50% complete, estimated complete at 5/12/10 2:09 PM.
14:07:11,596 User:System INFO [admin.patch.PatchExecuter] Patch patch.authorityDefaultZonesPatch 60% complete, estimated complete at 5/12/10 2:09 PM.
14:07:33,974 User:System INFO [admin.patch.PatchExecuter] Patch patch.authorityDefaultZonesPatch 70% complete, estimated complete at 5/12/10 2:08 PM.
14:10:08,671 INFO [admin.patch.PatchExecuter] Applying patch 'patch.imapFolders' (Creates folders tree necessary for IMAP functionality).
14:10:38,611 INFO [admin.patch.PatchExecuter] Applying patch 'patch.personUsagePatch' (Add person 'cm:sizeCurrent' property (if missing).).
14:10:38,611 User:System INFO [patch.impl.PersonUsagePatch] Checking for people with missing 'cm:sizeCurrent' property …
14:10:38,938 User:System INFO [patch.impl.PersonUsagePatch] … no people were missing the 'cm:sizeCurrent' property
14:10:38,949 INFO [admin.patch.PatchExecuter] Applying patch 'patch.redeployNominatedInvitationProcessWithPropsForShare' (Redeploy nominated invitation workflow).
14:10:39,049 INFO [admin.patch.PatchExecuter] Applying patch 'patch.rendition.rendering_actions' (Creates the Rendering Actions folder.).
14:10:39,266 INFO [admin.patch.PatchExecuter] Applying patch 'patch.thumbnailsAssocQName' (Update the 'cm:thumbnails' association QName to 'rn:rendition'.).
14:10:39,271 INFO [admin.patch.PatchExecuter] Applying patch 'patch.emailInviteAndNotifyTemplatesFolder' (Ensures the existence of the 'Email Invite Templates' and 'Email Notify Templates' folders.).
14:10:39,513 INFO [admin.patch.PatchExecuter] Applying patch 'patch.convertContentUrls' (Converts pre-3.2 content URLs to use the alf_content_data table. The conversion work can also be done on a schedule; please contact Alfresco Support for further details.).
14:10:39,526 User:System INFO [admin.patch.PatchExecuter] Content URL conversion progress:
14:10:39,527 User:System INFO [admin.patch.PatchExecuter] Processing ADM Content URLs.
14:10:59,927 User:System INFO [admin.patch.PatchExecuter] Patch patch.convertContentUrls 10% complete, estimated complete at 5/12/10 2:14 PM.
### Excluding compile: org.alfresco.repo.search.impl.lucene.index.IndexInfo$Merger::mergeIndexes
14:11:54,085 User:System INFO [admin.patch.PatchExecuter] Patch patch.convertContentUrls 20% complete, estimated complete at 5/12/10 2:16 PM.
14:12:56,154 User:System INFO [admin.patch.PatchExecuter] Patch patch.convertContentUrls 30% complete, estimated complete at 5/12/10 2:18 PM.
14:13:29,047 User:System INFO [admin.patch.PatchExecuter] Patch patch.convertContentUrls 40% complete, estimated complete at 5/12/10 2:17 PM.
14:13:57,375 User:System INFO [admin.patch.PatchExecuter] Patch patch.convertContentUrls 50% complete, estimated complete at 5/12/10 2:17 PM.
14:14:33,224 User:System INFO [admin.patch.PatchExecuter] Patch patch.convertContentUrls 60% complete, estimated complete at 5/12/10 2:17 PM.
14:15:09,746 User:System INFO [admin.patch.PatchExecuter] Patch patch.convertContentUrls 70% complete, estimated complete at 5/12/10 2:17 PM.
14:15:55,998 User:System INFO [admin.patch.PatchExecuter] Patch patch.convertContentUrls 80% complete, estimated complete at 5/12/10 2:17 PM.
14:17:22,552 User:System INFO [admin.patch.PatchExecuter] Finished processing ADM nodes up to ID 3,386,226.
14:17:22,670 User:System INFO [admin.patch.PatchExecuter] Processing AVM Content URLs.
14:17:23,084 User:System INFO [admin.patch.PatchExecuter] Finished processing AVM nodes up to ID 3.
14:17:23,221 User:System INFO [admin.patch.PatchExecuter] Reading content URLs from store FileContentStore[ root=/opt/alfresco_api/alf_data/contentstore, allowRandomAccess=true, readOnly=false].
14:18:11,429 User:System INFO [admin.patch.PatchExecuter] Processed 500 content URLs from store.
14:18:12,232 User:System INFO [admin.patch.PatchExecuter] Processed 1,000 content URLs from store.
14:18:13,127 User:System INFO [admin.patch.PatchExecuter] Processed 1,500 content URLs from store.
14:18:14,147 User:System INFO [admin.patch.PatchExecuter] Processed 2,000 content URLs from store.
14:18:15,218 User:System INFO [admin.patch.PatchExecuter] Processed 2,500 content URLs from store.
14:18:16,493 User:System INFO [admin.patch.PatchExecuter] Processed 3,000 content URLs from store.
14:18:17,751 User:System INFO [admin.patch.PatchExecuter] Processed 3,500 content URLs from store.
…
14:32:56,945 User:System INFO [admin.patch.PatchExecuter] Processed 34,000 content URLs from store.
14:33:25,731 User:System INFO [admin.patch.PatchExecuter] Processed 34,500 content URLs from store.
14:33:54,770 User:System INFO [admin.patch.PatchExecuter] Processed 35,000 content URLs from store.
14:34:24,342 User:System INFO [admin.patch.PatchExecuter] Processed 35,500 content URLs from store.
14:34:54,196 User:System INFO [admin.patch.PatchExecuter] Processed 36,000 content URLs from store.
14:35:24,437 User:System INFO [admin.patch.PatchExecuter] Processed 36,500 content URLs from store.
14:39:23,399 User:System INFO [admin.patch.PatchExecuter] Processed 500 content URLs from store.
14:39:24,278 User:System INFO [admin.patch.PatchExecuter] Processed 1,000 content URLs from store.
14:39:25,268 User:System INFO [admin.patch.PatchExecuter] Processed 1,500 content URLs from store.
14:39:26,363 User:System INFO [admin.patch.PatchExecuter] Processed 2,000 content URLs from store.
14:39:27,607 User:System INFO [admin.patch.PatchExecuter] Processed 2,500 content URLs from store.
14:39:29,031 User:System INFO [admin.patch.PatchExecuter] Processed 3,000 content URLs from store.
…
14:52:14,864 User:System INFO [admin.patch.PatchExecuter] Processed 30,000 content URLs from store.
14:52:41,225 User:System INFO [admin.patch.PatchExecuter] Processed 30,500 content URLs from store.
14:53:07,773 User:System INFO [admin.patch.PatchExecuter] Processed 31,000 content URLs from store.
14:53:34,747 User:System INFO [admin.patch.PatchExecuter] Processed 31,500 content URLs from store.
14:54:02,045 User:System INFO [admin.patch.PatchExecuter] Processed 32,000 content URLs from store.
…