AnsweredAssumed Answered

Lock wait timeout.... again

Question asked by tanger on Sep 6, 2010
Hi,

I've found a lot of topics dedicated to "Lock wait timeout" problem, but unfortunately none of them contains any info that could help me…


Our application had been working quite ok for several months when one day we got the following error message:

ERROR [org.quartz.core.JobRunShell] Job DEFAULT.userUsageTrackingJobDetail threw an unhandled Exception:
org.springframework.dao.CannotAcquireLockException: Hibernate operation: could not execute update query; SQL [delete from alf_usage_delta where node_id=?]; Lock wait timeout exceeded; try restarting transaction; nested exception is java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction
Caused by: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction


I'm a bit confused about it:

1. Acording to wiki, "User Usage Tracking Component - to allow user usages to be collapsed or re-calculated - used by UserUsageCollapseJob to collapse usage deltas. - used on bootstrap to either clear all usages or (re-)calculate all missing usages." - so can we say it's alfresco bug which doesn't depends on our application?

2. I found jira item https://issues.alfresco.com/jira/browse/ALFCOM-2040 related to that problem, but it's mentioned that "it's not a bug" there. Fix version is 2.9, but I use Alfresco 3.1.

May be someone also have faced with the same problem - how did you solved it?

2010-09-03 01:11:58,220 INFO  [org.jboss.system.server.Server] [main] JBoss (MX MicroKernel) [4.2.2.GA (build: SVNTag=JBoss_4_2_2_GA date=200710221139)] Started in 1m:4s:240ms
2010-09-03 01:19:25,466 INFO  [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: starting /xxx/check.seam
2010-09-03 01:19:26,080 INFO  [STDOUT] [RMI TCP Connection(23)-192.168.129.59] 01:19:26,080 Tenant:xxx User:admin INFO  [net.company.product.service.edi.SpoolServiceImpl] Creating empty file <f5-check.tmp-daf2bda5-3502-4a8b-b61d-722d9001e1b8> in spool <workspace://SpacesStore/6f956092-cbbb-4be0-8952-a12601cd191d>.
2010-09-03 01:19:26,841 INFO  [facelets.compiler] [http-192.168.129.59-8080-2] Added Library from: jar:file:/www/local/services/product-application-prod-xxx/jboss/server/application/deploy/xxx.war/WEB-INF/lib/jboss-seam-ui-2.1.2.jar!/META-INF/s.taglib.xml
2010-09-03 01:19:26,858 INFO  [facelets.compiler] [http-192.168.129.59-8080-2] Added Library from: jar:file:/www/local/services/product-application-prod-xxx/jboss/server/application/deploy/xxx.war/WEB-INF/lib/jsf-facelets-1.1.14.jar!/META-INF/jsf-core.taglib.xml
2010-09-03 01:19:26,861 INFO  [facelets.compiler] [http-192.168.129.59-8080-2] Added Library from: jar:file:/www/local/services/product-application-prod-xxx/jboss/server/application/deploy/xxx.war/WEB-INF/lib/jsf-facelets-1.1.14.jar!/META-INF/jsf-html.taglib.xml
2010-09-03 01:19:26,869 INFO  [facelets.compiler] [http-192.168.129.59-8080-2] Added Library from: jar:file:/www/local/services/product-application-prod-xxx/jboss/server/application/deploy/xxx.war/WEB-INF/lib/jsf-facelets-1.1.14.jar!/META-INF/jsf-ui.taglib.xml
2010-09-03 01:19:26,876 INFO  [facelets.compiler] [http-192.168.129.59-8080-2] Added Library from: jar:file:/www/local/services/product-application-prod-xxx/jboss/server/application/deploy/xxx.war/WEB-INF/lib/jsf-facelets-1.1.14.jar!/META-INF/jstl-core.taglib.xml
2010-09-03 01:19:26,879 INFO  [facelets.compiler] [http-192.168.129.59-8080-2] Added Library from: jar:file:/www/local/services/product-application-prod-xxx/jboss/server/application/deploy/xxx.war/WEB-INF/lib/jsf-facelets-1.1.14.jar!/META-INF/jstl-fn.taglib.xml
2010-09-03 01:19:26,903 INFO  [facelets.compiler] [http-192.168.129.59-8080-2] Added Library from: jar:file:/www/local/services/product-application-prod-xxx/jboss/server/application/deploy/xxx.war/WEB-INF/lib/richfaces-ui-3.3.0.GA.jar!/META-INF/a4j.taglib.xml
2010-09-03 01:19:26,906 INFO  [facelets.compiler] [http-192.168.129.59-8080-2] Added Library from: jar:file:/www/local/services/product-application-prod-xxx/jboss/server/application/deploy/xxx.war/WEB-INF/lib/richfaces-ui-3.3.0.GA.jar!/META-INF/ajax4jsf.taglib.xml
2010-09-03 01:19:26,908 INFO  [facelets.compiler] [http-192.168.129.59-8080-2] Added Library from: jar:file:/www/local/services/product-application-prod-xxx/jboss/server/application/deploy/xxx.war/WEB-INF/lib/richfaces-ui-3.3.0.GA.jar!/META-INF/jsp.taglib.xml
2010-09-03 01:19:26,955 INFO  [facelets.compiler] [http-192.168.129.59-8080-2] Added Library from: jar:file:/www/local/services/product-application-prod-xxx/jboss/server/application/deploy/xxx.war/WEB-INF/lib/richfaces-ui-3.3.0.GA.jar!/META-INF/rich.taglib.xml
2010-09-03 01:19:26,959 INFO  [facelets.compiler] [http-192.168.129.59-8080-2] Added Library from: jar:file:/www/local/services/product-application-prod-xxx/jboss/server/application/deploy/xxx.war/WEB-INF/lib/richfaces-ui-3.3.0.GA.jar!/META-INF/richfaces.taglib.xml
2010-09-03 01:19:27,032 INFO  User:admin@xxx [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: finished /xxx/check.seam in 1567ms
2010-09-03 01:36:24,779 INFO  [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: starting /xxx/check.seam
2010-09-03 01:36:24,909 INFO  [STDOUT] [RMI TCP Connection(49)-192.168.129.59] 01:36:24,909 Tenant:xxx User:admin INFO  [net.company.product.service.edi.SpoolServiceImpl] Creating empty file <f5-check.tmp-3e28dc18-c530-44a1-8767-fa461e050cef> in spool <workspace://SpacesStore/6f956092-cbbb-4be0-8952-a12601cd191d>.
2010-09-03 01:36:25,114 INFO  User:admin@xxx [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: finished /xxx/check.seam in 335ms
2010-09-03 01:52:55,521 INFO  [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: starting /xxx/check.seam
2010-09-03 01:52:55,652 INFO  [STDOUT] [RMI TCP Connection(81)-192.168.129.59] 01:52:55,651 Tenant:xxx User:admin INFO  [net.company.product.service.edi.SpoolServiceImpl] Creating empty file <f5-check.tmp-28b85367-0f92-4cb0-a302-dca22fcfd58d> in spool <workspace://SpacesStore/6f956092-cbbb-4be0-8952-a12601cd191d>.
2010-09-03 01:52:55,886 INFO  User:admin@xxx [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: finished /xxx/check.seam in 365ms
2010-09-03 02:09:17,910 INFO  [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: starting /xxx/check.seam
2010-09-03 02:09:18,032 INFO  [STDOUT] [RMI TCP Connection(106)-192.168.129.59] 02:09:18,032 Tenant:xxx User:admin INFO  [net.company.product.service.edi.SpoolServiceImpl] Creating empty file <f5-check.tmp-9ca93d66-85fc-4ae3-965b-c32a16998bd5> in spool <workspace://SpacesStore/6f956092-cbbb-4be0-8952-a12601cd191d>.
2010-09-03 02:09:18,197 INFO  User:admin@xxx [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: finished /xxx/check.seam in 287ms
2010-09-03 02:25:56,653 INFO  [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: starting /xxx/check.seam
2010-09-03 02:25:56,770 INFO  [STDOUT] [RMI TCP Connection(131)-192.168.129.59] 02:25:56,769 Tenant:xxx User:admin INFO  [net.company.product.service.edi.SpoolServiceImpl] Creating empty file <f5-check.tmp-48805f01-dccb-4d69-ad43-ec74ea4a9d91> in spool <workspace://SpacesStore/6f956092-cbbb-4be0-8952-a12601cd191d>.
2010-09-03 02:25:56,940 INFO  User:admin@xxx [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: finished /xxx/check.seam in 287ms
2010-09-03 02:42:30,015 INFO  [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: starting /xxx/check.seam
2010-09-03 02:42:30,149 INFO  [STDOUT] [RMI TCP Connection(164)-192.168.129.59] 02:42:30,149 Tenant:xxx User:admin INFO  [net.company.product.service.edi.SpoolServiceImpl] Creating empty file <f5-check.tmp-4b32a10a-8516-4758-83d4-d5ce1c643028> in spool <workspace://SpacesStore/6f956092-cbbb-4be0-8952-a12601cd191d>.
2010-09-03 02:42:30,332 INFO  User:admin@xxx [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: finished /xxx/check.seam in 317ms
2010-09-03 02:59:00,128 INFO  [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: starting /xxx/check.seam
2010-09-03 02:59:00,244 INFO  [STDOUT] [RMI TCP Connection(189)-192.168.129.59] 02:59:00,244 Tenant:xxx User:admin INFO  [net.company.product.service.edi.SpoolServiceImpl] Creating empty file <f5-check.tmp-1df2853e-2481-4766-bead-2b6034ec0821> in spool <workspace://SpacesStore/6f956092-cbbb-4be0-8952-a12601cd191d>.
2010-09-03 02:59:01,064 INFO  User:admin@xxx [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: finished /xxx/check.seam in 936ms
2010-09-03 03:16:01,103 INFO  [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: starting /xxx/check.seam
2010-09-03 03:16:01,216 INFO  [STDOUT] [RMI TCP Connection(214)-192.168.129.59] 03:16:01,215 Tenant:xxx User:admin INFO  [net.company.product.service.edi.SpoolServiceImpl] Creating empty file <f5-check.tmp-2caea644-6b6c-47d6-be1d-9009b78f0265> in spool <workspace://SpacesStore/6f956092-cbbb-4be0-8952-a12601cd191d>.
2010-09-03 03:16:01,394 INFO  User:admin@xxx [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: finished /xxx/check.seam in 291ms
2010-09-03 03:32:42,054 INFO  [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: starting /xxx/check.seam
2010-09-03 03:32:42,171 INFO  [STDOUT] [RMI TCP Connection(247)-192.168.129.59] 03:32:42,171 Tenant:xxx User:admin INFO  [net.company.product.service.edi.SpoolServiceImpl] Creating empty file <f5-check.tmp-8f0c5e21-a71e-495e-aed2-009501103511> in spool <workspace://SpacesStore/6f956092-cbbb-4be0-8952-a12601cd191d>.
2010-09-03 03:32:42,330 INFO  User:admin@xxx [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: finished /xxx/check.seam in 276ms
2010-09-03 03:49:13,986 INFO  [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: starting /xxx/check.seam
2010-09-03 03:49:14,096 INFO  [STDOUT] [RMI TCP Connection(272)-192.168.129.59] 03:49:14,096 Tenant:xxx User:admin INFO  [net.company.product.service.edi.SpoolServiceImpl] Creating empty file <f5-check.tmp-c362586d-5370-4eb0-a25d-9b5b77e2e25b> in spool <workspace://SpacesStore/6f956092-cbbb-4be0-8952-a12601cd191d>.
2010-09-03 03:49:14,266 INFO  User:admin@xxx [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: finished /xxx/check.seam in 280ms
2010-09-03 04:06:28,770 INFO  [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: starting /xxx/check.seam
2010-09-03 04:06:28,883 INFO  [STDOUT] [RMI TCP Connection(304)-192.168.129.59] 04:06:28,883 Tenant:xxx User:admin INFO  [net.company.product.service.edi.SpoolServiceImpl] Creating empty file <f5-check.tmp-56075a9b-1a81-42d4-9f1b-2b4a129ba99e> in spool <workspace://SpacesStore/6f956092-cbbb-4be0-8952-a12601cd191d>.
2010-09-03 04:06:29,103 INFO  User:admin@xxx [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: finished /xxx/check.seam in 333ms
2010-09-03 04:23:09,082 INFO  [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: starting /xxx/check.seam
2010-09-03 04:23:09,202 INFO  [STDOUT] [RMI TCP Connection(329)-192.168.129.59] 04:23:09,202 Tenant:xxx User:admin INFO  [net.company.product.service.edi.SpoolServiceImpl] Creating empty file <f5-check.tmp-e3bc176f-6c4b-41de-a20e-92deec7d7935> in spool <workspace://SpacesStore/6f956092-cbbb-4be0-8952-a12601cd191d>.
2010-09-03 04:23:09,446 INFO  User:admin@xxx [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: finished /xxx/check.seam in 364ms
2010-09-03 04:39:40,754 INFO  [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: starting /xxx/check.seam
2010-09-03 04:39:40,860 INFO  [STDOUT] [RMI TCP Connection(354)-192.168.129.59] 04:39:40,860 Tenant:xxx User:admin INFO  [net.company.product.service.edi.SpoolServiceImpl] Creating empty file <f5-check.tmp-df87439a-eb53-4c48-b9b7-09b2c6a51fcb> in spool <workspace://SpacesStore/6f956092-cbbb-4be0-8952-a12601cd191d>.
2010-09-03 04:39:41,016 INFO  User:admin@xxx [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: finished /xxx/check.seam in 261ms
2010-09-03 04:56:33,315 INFO  [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: starting /xxx/check.seam
2010-09-03 04:56:33,421 INFO  [STDOUT] [RMI TCP Connection(386)-192.168.129.59] 04:56:33,421 Tenant:xxx User:admin INFO  [net.company.product.service.edi.SpoolServiceImpl] Creating empty file <f5-check.tmp-461735d0-d093-4e8d-a3b9-166c28c6f123> in spool <workspace://SpacesStore/6f956092-cbbb-4be0-8952-a12601cd191d>.
2010-09-03 04:56:33,584 INFO  User:admin@xxx [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: finished /xxx/check.seam in 269ms
2010-09-03 05:11:38,281 INFO  [STDOUT] [DefaultScheduler_Worker-1] 05:11:38,281  WARN  [org.alfresco.enterprise.heartbeat.HeartBeat] java.net.SocketTimeoutException: connect timed out
2010-09-03 05:13:20,031 INFO  [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: starting /xxx/check.seam
2010-09-03 05:13:20,142 INFO  [STDOUT] [RMI TCP Connection(411)-192.168.129.59] 05:13:20,142 Tenant:xxx User:admin INFO  [net.company.product.service.edi.SpoolServiceImpl] Creating empty file <f5-check.tmp-2f3468d8-9313-4e84-a8bc-ed8e1ce50b95> in spool <workspace://SpacesStore/6f956092-cbbb-4be0-8952-a12601cd191d>.
2010-09-03 05:13:20,334 INFO  User:admin@xxx [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: finished /xxx/check.seam in 303ms
2010-09-03 05:16:59,466 INFO  [STDOUT] [defaultAsyncAction1] 05:16:59,464 User:user1@xxx  INFO  [net.company.product.edi.ImporterWrapper] ImportProcessor> Importing file …/user1/D.31AB475A.20100903.INDX.zip
2010-09-03 05:17:00,839 INFO  [STDOUT] [defaultAsyncAction1] 05:17:00,839 User:user1@xxx  INFO  [net.company.product.edi.ImportConfigParser] Routing rules parsed in 993 ms
2010-09-03 05:17:06,401 INFO  [STDOUT] [defaultAsyncAction1] 05:17:06,401 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #3
2010-09-03 05:17:06,820 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's e4d2a531-7239-4f9c-89b8-714761e5398b identifier to 64755
2010-09-03 05:17:06,946 INFO  [STDOUT] [defaultAsyncAction1] 05:17:06,946 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/e4d2a531-7239-4f9c-89b8-714761e5398b in category1 category MISCELLANEOUS
2010-09-03 05:17:06,947 INFO  [STDOUT] [defaultAsyncAction1] 05:17:06,947 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:17:08,143 INFO  [STDOUT] [defaultAsyncAction1] 05:17:08,142 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/0e594c05-2ee5-4cc8-9592-6e433d6be0fc (type id3)
2010-09-03 05:17:08,551 INFO  [STDOUT] [defaultAsyncAction1] 05:17:08,551 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/529ceaf0-0c42-4fbc-86f6-25dced9fd0f2 (type id3)
2010-09-03 05:17:08,812 INFO  [STDOUT] [defaultAsyncAction1] 05:17:08,812 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/2c5eef6c-24df-4fbf-a233-ac6703302e88 (type id3)
2010-09-03 05:17:09,154 INFO  [STDOUT] [defaultAsyncAction1] 05:17:09,154 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/de8b1df3-3e32-477b-90ee-b3925ab8687a (type id3)
2010-09-03 05:17:09,502 INFO  [STDOUT] [defaultAsyncAction1] 05:17:09,502 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/01f0adec-9efb-4031-a483-c00d7d7b2a8d (type id3)
2010-09-03 05:17:10,460 INFO  [STDOUT] [defaultAsyncAction1] 05:17:10,460 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/e56715fd-5454-40a1-88f9-6b1ce8b2ab5a (type id144)
2010-09-03 05:17:10,475 INFO  [STDOUT] [defaultAsyncAction1] 05:17:10,475 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:17:11,584 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 5a56d89c-bd58-4865-b685-fa0bb444752e identifier to 64756
2010-09-03 05:17:11,790 INFO  [STDOUT] [defaultAsyncAction1] 05:17:11,790 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/5a56d89c-bd58-4865-b685-fa0bb444752e in category1 category MISCELLANEOUS
2010-09-03 05:17:11,791 INFO  [STDOUT] [defaultAsyncAction1] 05:17:11,791 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:17:12,245 INFO  [STDOUT] [defaultAsyncAction1] 05:17:12,245 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/d49d1d14-3ac3-41a6-bfea-9b57f276d779 (type id144)
2010-09-03 05:17:12,664 INFO  [STDOUT] [defaultAsyncAction1] 05:17:12,664 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/e8fd2ee6-a36d-404e-adff-71d8e80bad3a (type id144)
2010-09-03 05:17:13,158 INFO  [STDOUT] [defaultAsyncAction1] 05:17:13,158 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/fc562c1b-cf41-4f1f-8d71-fbca6539768f (type id144)
2010-09-03 05:17:13,433 INFO  [STDOUT] [defaultAsyncAction1] 05:17:13,432 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:17:13,747 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 4920e980-5d63-4476-8c36-546571aa2e81 identifier to 64757
2010-09-03 05:17:13,900 INFO  [STDOUT] [defaultAsyncAction1] 05:17:13,900 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/4920e980-5d63-4476-8c36-546571aa2e81 in category1 category MISCELLANEOUS
2010-09-03 05:17:13,900 INFO  [STDOUT] [defaultAsyncAction1] 05:17:13,900 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:17:14,278 INFO  [STDOUT] [defaultAsyncAction1] 05:17:14,278 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/563c9b21-d6c1-42c9-8875-a04b9d8cde9f (type id3)
2010-09-03 05:17:14,288 INFO  [STDOUT] [defaultAsyncAction1] 05:17:14,288 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #3
2010-09-03 05:17:14,820 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 4cc1b149-3931-4ca9-9715-a459760cc096 identifier to 64758
2010-09-03 05:17:14,990 INFO  [STDOUT] [defaultAsyncAction1] 05:17:14,990 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/4cc1b149-3931-4ca9-9715-a459760cc096 in category1 category TKE
2010-09-03 05:17:14,990 INFO  [STDOUT] [defaultAsyncAction1] 05:17:14,990 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:17:15,412 INFO  [STDOUT] [defaultAsyncAction1] 05:17:15,412 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/7ee27a2a-9d3f-4614-8965-aa4de484624b (type id3)
2010-09-03 05:17:15,840 INFO  [STDOUT] [defaultAsyncAction1] 05:17:15,840 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/811d7cc9-8682-4a3d-a1ce-51c0e03eb07e (type id3)
2010-09-03 05:17:16,402 INFO  [STDOUT] [defaultAsyncAction1] 05:17:16,402 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/eca60765-2c6c-4148-aad9-fa3a161a3c3a (type id15)
2010-09-03 05:17:16,799 INFO  [STDOUT] [defaultAsyncAction1] 05:17:16,799 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/70ad9456-cf44-4c79-8154-c0519def6f80 (type id72)
2010-09-03 05:17:17,301 INFO  [STDOUT] [defaultAsyncAction1] 05:17:17,301 User:user1@xxx  INFO  [net.company.product.edi.ImportConditional$CountRecords] Found single target record: workspace://SpacesStore/f5d7520e-a388-45bb-be44-1ae2b102526a
2010-09-03 05:17:17,301 INFO  [STDOUT] [defaultAsyncAction1] 05:17:17,301 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #5
2010-09-03 05:17:18,253 INFO  [STDOUT] [defaultAsyncAction1] 05:17:18,253 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/1b4ad4b5-a897-43d5-bca1-59a126461c83 (type id3)
2010-09-03 05:17:18,253 INFO  [STDOUT] [defaultAsyncAction1] 05:17:18,253 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #3
2010-09-03 05:17:19,026 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's dd22b5a1-683a-4172-8987-0f984143d56f identifier to 64759
2010-09-03 05:17:19,276 INFO  [STDOUT] [defaultAsyncAction1] 05:17:19,276 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/dd22b5a1-683a-4172-8987-0f984143d56f in category1 category TTE
2010-09-03 05:17:19,277 INFO  [STDOUT] [defaultAsyncAction1] 05:17:19,277 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:17:19,858 INFO  [STDOUT] [defaultAsyncAction1] 05:17:19,858 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/6336cac2-0ace-41fc-b4f0-74af647731c3 (type id20)
2010-09-03 05:17:19,967 INFO  [STDOUT] [defaultAsyncAction1] 05:17:19,967 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:17:20,456 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 51b2949c-ed6e-4e35-9a31-eb7dde856c15 identifier to 64760
2010-09-03 05:17:20,676 INFO  [STDOUT] [defaultAsyncAction1] 05:17:20,676 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/51b2949c-ed6e-4e35-9a31-eb7dde856c15 in category1 category MISCELLANEOUS
2010-09-03 05:17:20,677 INFO  [STDOUT] [defaultAsyncAction1] 05:17:20,677 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:17:21,152 INFO  [STDOUT] [defaultAsyncAction1] 05:17:21,152 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/e3acbbec-3f1c-4d07-bce8-4e5b447699ed (type id3)
2010-09-03 05:17:21,249 INFO  [STDOUT] [defaultAsyncAction1] 05:17:21,249 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:17:21,765 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 93c2d061-790e-4e8e-a903-9b777161ba3c identifier to 64761
2010-09-03 05:17:21,990 INFO  [STDOUT] [defaultAsyncAction1] 05:17:21,990 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/93c2d061-790e-4e8e-a903-9b777161ba3c in category1 category MISCELLANEOUS
2010-09-03 05:17:21,990 INFO  [STDOUT] [defaultAsyncAction1] 05:17:21,990 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:17:22,515 INFO  [STDOUT] [defaultAsyncAction1] 05:17:22,515 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/2b77a94d-617a-4268-ab6a-f7545e75867b (type id72)
2010-09-03 05:17:23,031 INFO  [STDOUT] [defaultAsyncAction1] 05:17:23,031 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/8b35c69f-9f6e-4ce0-9bad-000740bfd73d (type id3)
2010-09-03 05:17:23,044 INFO  [STDOUT] [defaultAsyncAction1] 05:17:23,044 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #3
2010-09-03 05:17:23,852 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 246467fb-432c-4a6c-8d6b-9dc5ec31230f identifier to 64762
2010-09-03 05:17:24,165 INFO  [STDOUT] [defaultAsyncAction1] 05:17:24,165 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/246467fb-432c-4a6c-8d6b-9dc5ec31230f in category1 category VE
2010-09-03 05:17:24,166 INFO  [STDOUT] [defaultAsyncAction1] 05:17:24,166 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:17:24,816 INFO  [STDOUT] [defaultAsyncAction1] 05:17:24,816 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/41ceea9f-40d4-4a1d-a812-368802d230e6 (type id11)
2010-09-03 05:17:24,830 INFO  [STDOUT] [defaultAsyncAction1] 05:17:24,830 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #3
2010-09-03 05:17:25,711 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's e20a2a07-3fa5-43e8-b888-f387d5ddf8a8 identifier to 64763
2010-09-03 05:17:25,992 INFO  [STDOUT] [defaultAsyncAction1] 05:17:25,992 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/e20a2a07-3fa5-43e8-b888-f387d5ddf8a8 in category1 category TKE
2010-09-03 05:17:25,993 INFO  [STDOUT] [defaultAsyncAction1] 05:17:25,992 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:17:26,577 INFO  [STDOUT] [defaultAsyncAction1] 05:17:26,576 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/93c770b3-bcd5-4523-a57f-77e9edd2c864 (type id15)
2010-09-03 05:17:27,158 INFO  [STDOUT] [defaultAsyncAction1] 05:17:27,158 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/67975536-6c33-438e-8fc2-420896e5fa0c (type id3)
2010-09-03 05:17:27,639 INFO  [STDOUT] [defaultAsyncAction1] 05:17:27,639 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/53b415e8-8c3c-43a3-800a-c97e6f4cdefb (type id3)
2010-09-03 05:17:28,119 INFO  [STDOUT] [defaultAsyncAction1] 05:17:28,119 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/237b089d-53fd-4b88-8cac-0d5edd998996 (type id3)
2010-09-03 05:17:28,625 INFO  [STDOUT] [defaultAsyncAction1] 05:17:28,625 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/6ac243b6-65b1-45ad-b2b8-b8eb480362e8 (type id3)
2010-09-03 05:17:29,151 INFO  [STDOUT] [defaultAsyncAction1] 05:17:29,151 User:user1@xxx  INFO  [net.company.product.edi.ImportConditional$CountRecords] Found single target record: workspace://SpacesStore/1f132a35-5fa2-4d48-a847-36d7606bc5e9
2010-09-03 05:17:29,151 INFO  [STDOUT] [defaultAsyncAction1] 05:17:29,151 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #5
2010-09-03 05:17:29,985 INFO  [STDOUT] [defaultAsyncAction1] 05:17:29,985 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/947c3414-839e-4aaf-adf7-7eabd74d3600 (type id3)
2010-09-03 05:17:29,985 INFO  [STDOUT] [defaultAsyncAction1] 05:17:29,985 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:17:30,521 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 9199439e-ba33-44b4-9556-e2d258f20862 identifier to 64764
2010-09-03 05:17:30,772 INFO  [STDOUT] [defaultAsyncAction1] 05:17:30,772 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/9199439e-ba33-44b4-9556-e2d258f20862 in category1 category MISCELLANEOUS
2010-09-03 05:17:30,772 INFO  [STDOUT] [defaultAsyncAction1] 05:17:30,772 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:17:31,413 INFO  [STDOUT] [defaultAsyncAction1] 05:17:31,413 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/4f69795e-08db-45c5-ad39-c0b8e04443d4 (type id15)
2010-09-03 05:17:31,899 INFO  [STDOUT] [defaultAsyncAction1] 05:17:31,899 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/12a0219e-b553-400c-b2ee-e3ded4048231 (type id3)
2010-09-03 05:17:32,365 INFO  [STDOUT] [defaultAsyncAction1] 05:17:32,365 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/98916326-9680-4451-9338-55ceffa0dc96 (type id3)
2010-09-03 05:17:32,822 INFO  [STDOUT] [defaultAsyncAction1] 05:17:32,822 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/945d8994-43cf-4a68-b5e0-bb8c4dd527e2 (type id3)
2010-09-03 05:17:33,323 INFO  [STDOUT] [defaultAsyncAction1] 05:17:33,323 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/1f0554a6-10f2-4505-ba85-42487f20d2c4 (type id3)
2010-09-03 05:17:33,796 INFO  [STDOUT] [defaultAsyncAction1] 05:17:33,796 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/eb4c9905-c337-4a05-80de-5280ee7e9d81 (type id3)
2010-09-03 05:17:34,299 INFO  [STDOUT] [defaultAsyncAction1] 05:17:34,299 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/f45e11d3-8375-48ca-9c92-7c629ba5d9fa (type id15)
2010-09-03 05:17:34,770 INFO  [STDOUT] [defaultAsyncAction1] 05:17:34,770 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/b6fb9f81-b246-4cb1-9271-ae490c068048 (type id3)
2010-09-03 05:17:35,329 INFO  [STDOUT] [defaultAsyncAction1] 05:17:35,329 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/9545bf04-7bd8-44e8-8866-d3550afadad2 (type id15)
2010-09-03 05:17:35,342 INFO  [STDOUT] [defaultAsyncAction1] 05:17:35,342 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #2
2010-09-03 05:17:36,206 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 4ea7c04c-dacb-4165-9f4a-61c0703b045a identifier to 64765
2010-09-03 05:17:36,468 INFO  [STDOUT] [defaultAsyncAction1] 05:17:36,468 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/4ea7c04c-dacb-4165-9f4a-61c0703b045a in category1 category PE
2010-09-03 05:17:36,469 INFO  [STDOUT] [defaultAsyncAction1] 05:17:36,469 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:true, record:true, cache only:false
2010-09-03 05:17:37,055 INFO  [STDOUT] [defaultAsyncAction1] 05:17:37,055 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/86195517-7307-42ca-a2a7-b2b3f19f3e52 (type id16)
2010-09-03 05:17:37,069 INFO  [STDOUT] [defaultAsyncAction1] 05:17:37,068 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:17:37,961 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 8f6da99c-7d9f-49d4-b4be-4e4ff24dbed7 identifier to 64766
2010-09-03 05:17:38,219 INFO  [STDOUT] [defaultAsyncAction1] 05:17:38,219 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/8f6da99c-7d9f-49d4-b4be-4e4ff24dbed7 in category1 category MISCELLANEOUS
2010-09-03 05:17:38,219 INFO  [STDOUT] [defaultAsyncAction1] 05:17:38,219 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:17:38,848 INFO  [STDOUT] [defaultAsyncAction1] 05:17:38,847 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/0de78e64-ae67-4366-b7a2-a84bcdb3b817 (type id144)
2010-09-03 05:17:39,397 INFO  [STDOUT] [defaultAsyncAction1] 05:17:39,397 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/cfb2546e-c063-4682-bd18-c69510aceb6d (type id144)
2010-09-03 05:17:39,638 INFO  [STDOUT] [defaultAsyncAction1] 05:17:39,638 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:17:40,173 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's e696b8a5-dcb1-472a-b284-6179f756d65b identifier to 64767
2010-09-03 05:17:40,425 INFO  [STDOUT] [defaultAsyncAction1] 05:17:40,425 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/e696b8a5-dcb1-472a-b284-6179f756d65b in category1 category MISCELLANEOUS
2010-09-03 05:17:40,425 INFO  [STDOUT] [defaultAsyncAction1] 05:17:40,425 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:17:41,042 INFO  [STDOUT] [defaultAsyncAction1] 05:17:41,042 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/5737c8c4-f491-445f-aeb7-8172406ddd6b (type id3)
2010-09-03 05:17:41,151 INFO  [STDOUT] [defaultAsyncAction1] 05:17:41,151 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:17:41,692 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 58f2ea9b-8cb9-4c42-a989-a69cffe44928 identifier to 64768
2010-09-03 05:17:41,966 INFO  [STDOUT] [defaultAsyncAction1] 05:17:41,966 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/58f2ea9b-8cb9-4c42-a989-a69cffe44928 in category1 category MISCELLANEOUS
2010-09-03 05:17:41,967 INFO  [STDOUT] [defaultAsyncAction1] 05:17:41,967 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:17:42,518 INFO  [STDOUT] [defaultAsyncAction1] 05:17:42,518 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/8a86ff40-2bf6-4861-a6bc-7334d44887c3 (type id3)
2010-09-03 05:17:42,532 INFO  [STDOUT] [defaultAsyncAction1] 05:17:42,532 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #3
2010-09-03 05:17:43,153 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's d005a124-e3f1-4ebd-9739-283c0f2bcc2f identifier to 64769
2010-09-03 05:17:43,435 INFO  [STDOUT] [defaultAsyncAction1] 05:17:43,435 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/d005a124-e3f1-4ebd-9739-283c0f2bcc2f in category1 category TKE
2010-09-03 05:17:43,436 INFO  [STDOUT] [defaultAsyncAction1] 05:17:43,435 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:17:44,016 INFO  [STDOUT] [defaultAsyncAction1] 05:17:44,016 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/be04f4e3-2799-414a-b08a-7b0ce4583d92 (type id3)
2010-09-03 05:17:44,550 INFO  [STDOUT] [defaultAsyncAction1] 05:17:44,549 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/c989801a-29eb-45a4-b8c6-29558996d6ce (type id3)
2010-09-03 05:17:45,088 INFO  [STDOUT] [defaultAsyncAction1] 05:17:45,088 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/9997fab9-f7c1-45b2-9b53-20257e8d2fe0 (type id3)
2010-09-03 05:17:45,654 INFO  [STDOUT] [defaultAsyncAction1] 05:17:45,654 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/b12f0d99-11ee-4f01-9c23-c03156b7273b (type id15)
2010-09-03 05:17:46,214 INFO  [STDOUT] [defaultAsyncAction1] 05:17:46,214 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/e3995afe-8720-4fa3-9235-4b596bba15b5 (type id3)
2010-09-03 05:17:46,227 INFO  [STDOUT] [defaultAsyncAction1] 05:17:46,227 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #3
2010-09-03 05:17:47,417 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 49e1afe5-e945-4b47-9e70-8797a6f4b454 identifier to 64770
2010-09-03 05:17:47,711 INFO  [STDOUT] [defaultAsyncAction1] 05:17:47,711 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/49e1afe5-e945-4b47-9e70-8797a6f4b454 in category1 category TKE
2010-09-03 05:17:47,712 INFO  [STDOUT] [defaultAsyncAction1] 05:17:47,712 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:17:48,297 INFO  [STDOUT] [defaultAsyncAction1] 05:17:48,297 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/c02f5d3e-ba0f-463a-8816-ec5573b81548 (type id3)
2010-09-03 05:17:48,876 INFO  [STDOUT] [defaultAsyncAction1] 05:17:48,876 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/b7736d99-edaa-4d75-a762-700d19fe2412 (type id72)
2010-09-03 05:17:49,504 INFO  [STDOUT] [defaultAsyncAction1] 05:17:49,504 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/9512f6f8-b3b0-475e-87fd-7f3dac53425a (type id15)
2010-09-03 05:17:50,060 INFO  [STDOUT] [defaultAsyncAction1] 05:17:50,060 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/22cdf6ce-756e-4d28-9b66-b4e52952119d (type id3)
2010-09-03 05:17:50,629 INFO  [STDOUT] [defaultAsyncAction1] 05:17:50,629 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/4bb7d34e-1d40-43d7-a343-9b7447be4d65 (type id3)
2010-09-03 05:17:51,190 INFO  [STDOUT] [defaultAsyncAction1] 05:17:51,190 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/b86a9fa5-b6c8-4406-a100-59edd8f6111d (type id3)
2010-09-03 05:17:51,204 INFO  [STDOUT] [defaultAsyncAction1] 05:17:51,204 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #2
2010-09-03 05:17:51,998 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 29f15b0d-23e2-4bb2-8832-ca51f4bb1817 identifier to 64771
2010-09-03 05:17:52,292 INFO  [STDOUT] [defaultAsyncAction1] 05:17:52,292 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/29f15b0d-23e2-4bb2-8832-ca51f4bb1817 in category1 category PE
2010-09-03 05:17:52,293 INFO  [STDOUT] [defaultAsyncAction1] 05:17:52,293 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:true, record:true, cache only:false
2010-09-03 05:17:52,941 INFO  [STDOUT] [defaultAsyncAction1] 05:17:52,941 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/934ce64b-3eac-4a62-9193-e196788b2208 (type id16)
2010-09-03 05:17:53,524 INFO  [STDOUT] [defaultAsyncAction1] 05:17:53,524 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/945e7b6f-5712-4b6a-957a-4c307318b355 (type id16)
2010-09-03 05:17:53,668 INFO  [STDOUT] [defaultAsyncAction1] 05:17:53,668 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:17:54,105 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 3ff7fa3e-a28d-4ed8-b0ba-72a1254ecbc7 identifier to 64772
2010-09-03 05:17:54,381 INFO  [STDOUT] [defaultAsyncAction1] 05:17:54,381 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/3ff7fa3e-a28d-4ed8-b0ba-72a1254ecbc7 in category1 category MISCELLANEOUS
2010-09-03 05:17:54,381 INFO  [STDOUT] [defaultAsyncAction1] 05:17:54,381 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:17:55,017 INFO  [STDOUT] [defaultAsyncAction1] 05:17:55,017 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/5208baf1-6776-451f-91e9-809d61e71725 (type id3)
2010-09-03 05:17:55,116 INFO  [STDOUT] [defaultAsyncAction1] 05:17:55,116 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:17:55,700 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 856bcffb-56ab-4eba-953e-c32a52df3f47 identifier to 64773
2010-09-03 05:17:55,990 INFO  [STDOUT] [defaultAsyncAction1] 05:17:55,990 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/856bcffb-56ab-4eba-953e-c32a52df3f47 in category1 category MISCELLANEOUS
2010-09-03 05:17:55,990 INFO  [STDOUT] [defaultAsyncAction1] 05:17:55,990 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:17:56,591 INFO  [STDOUT] [defaultAsyncAction1] 05:17:56,591 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/8125716d-21e9-4696-bac7-3a4806de2e00 (type id3)
2010-09-03 05:17:56,605 INFO  [STDOUT] [defaultAsyncAction1] 05:17:56,605 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:17:57,748 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's b759cd34-b750-41f5-aa9d-0b25300513ac identifier to 64774
2010-09-03 05:17:58,028 INFO  [STDOUT] [defaultAsyncAction1] 05:17:58,027 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/b759cd34-b750-41f5-aa9d-0b25300513ac in category1 category MISCELLANEOUS
2010-09-03 05:17:58,028 INFO  [STDOUT] [defaultAsyncAction1] 05:17:58,028 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:17:58,657 INFO  [STDOUT] [defaultAsyncAction1] 05:17:58,657 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/45e5ea1f-35ab-4ac6-b28e-1ce8d3fd6a52 (type id144)
2010-09-03 05:17:59,247 INFO  [STDOUT] [defaultAsyncAction1] 05:17:59,247 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/a3330274-5f56-44f1-9533-c95a89c6becb (type id144)
2010-09-03 05:17:59,467 INFO  [STDOUT] [defaultAsyncAction1] 05:17:59,467 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:18:00,051 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's a4da6b68-a2e7-4fe5-bd49-bc578c77d4a8 identifier to 64775
2010-09-03 05:18:00,348 INFO  [STDOUT] [defaultAsyncAction1] 05:18:00,348 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/a4da6b68-a2e7-4fe5-bd49-bc578c77d4a8 in category1 category MISCELLANEOUS
2010-09-03 05:18:00,348 INFO  [STDOUT] [defaultAsyncAction1] 05:18:00,348 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:18:00,977 INFO  [STDOUT] [defaultAsyncAction1] 05:18:00,976 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/ee34970e-6de8-484d-a7e8-8292a4612af4 (type id3)
2010-09-03 05:18:01,071 INFO  [STDOUT] [defaultAsyncAction1] 05:18:01,071 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:18:01,690 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's e889aefd-2927-4196-bffc-f08f9d72a777 identifier to 64776
2010-09-03 05:18:01,978 INFO  [STDOUT] [defaultAsyncAction1] 05:18:01,978 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/e889aefd-2927-4196-bffc-f08f9d72a777 in category1 category MISCELLANEOUS
2010-09-03 05:18:01,979 INFO  [STDOUT] [defaultAsyncAction1] 05:18:01,979 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:18:02,635 INFO  [STDOUT] [defaultAsyncAction1] 05:18:02,635 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/f561a532-2b0a-4dac-893d-e207d41c0008 (type id72)
2010-09-03 05:18:03,214 INFO  [STDOUT] [defaultAsyncAction1] 05:18:03,214 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/f5984470-e1bf-43db-951e-a2b8c179ae97 (type id3)
2010-09-03 05:18:03,229 INFO  [STDOUT] [defaultAsyncAction1] 05:18:03,229 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #3
2010-09-03 05:18:03,985 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 640c4f3e-be7d-415b-9d8c-80547c9742b8 identifier to 64777
2010-09-03 05:18:04,301 INFO  [STDOUT] [defaultAsyncAction1] 05:18:04,301 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/640c4f3e-be7d-415b-9d8c-80547c9742b8 in category1 category TKE
2010-09-03 05:18:04,301 INFO  [STDOUT] [defaultAsyncAction1] 05:18:04,301 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:18:04,969 INFO  [STDOUT] [defaultAsyncAction1] 05:18:04,969 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/a36cee0b-c033-4580-85da-c18337adc2ca (type id15)
2010-09-03 05:18:05,586 INFO  [STDOUT] [defaultAsyncAction1] 05:18:05,585 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/9ee3c509-0b88-43f4-a3c0-5f1cd1ff8fb5 (type id3)
2010-09-03 05:18:06,189 INFO  [STDOUT] [defaultAsyncAction1] 05:18:06,189 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/be59b2bc-fd43-4b8c-8d22-a34c6b9bce23 (type id3)
2010-09-03 05:18:06,797 INFO  [STDOUT] [defaultAsyncAction1] 05:18:06,797 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/f12762c8-3dd3-47b0-8f9b-fa27d8d74739 (type id3)
2010-09-03 05:18:07,403 INFO  [STDOUT] [defaultAsyncAction1] 05:18:07,403 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/ee8c7eff-e5a2-4bac-9a71-c7153ea8cbdc (type id3)
2010-09-03 05:18:07,418 INFO  [STDOUT] [defaultAsyncAction1] 05:18:07,418 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #2
2010-09-03 05:18:08,848 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's c369cce6-b048-4d5a-82bc-64ed6ed4828a identifier to 64778
2010-09-03 05:18:09,169 INFO  [STDOUT] [defaultAsyncAction1] 05:18:09,169 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/c369cce6-b048-4d5a-82bc-64ed6ed4828a in category1 category PE
2010-09-03 05:18:09,169 INFO  [STDOUT] [defaultAsyncAction1] 05:18:09,169 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:true, record:true, cache only:false
2010-09-03 05:18:09,854 INFO  [STDOUT] [defaultAsyncAction1] 05:18:09,854 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/2ea2d041-e6ec-41e5-b611-b3034c16337b (type id16)
2010-09-03 05:18:09,869 INFO  [STDOUT] [defaultAsyncAction1] 05:18:09,869 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #3
2010-09-03 05:18:10,486 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 48276e27-c3d4-449e-a03c-92a47f680090 identifier to 64779
2010-09-03 05:18:10,812 INFO  [STDOUT] [defaultAsyncAction1] 05:18:10,812 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/48276e27-c3d4-449e-a03c-92a47f680090 in category1 category TKE
2010-09-03 05:18:10,813 INFO  [STDOUT] [defaultAsyncAction1] 05:18:10,813 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:18:11,479 INFO  [STDOUT] [defaultAsyncAction1] 05:18:11,479 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/fd1c308a-52ab-4834-a993-85e1874a61de (type id3)
2010-09-03 05:18:12,102 INFO  [STDOUT] [defaultAsyncAction1] 05:18:12,102 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/9a726951-0cde-42b2-9021-1594c2e5e47a (type id72)
2010-09-03 05:18:12,724 INFO  [STDOUT] [defaultAsyncAction1] 05:18:12,724 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/bc612f41-2f0c-473b-84a3-8473dae2ffdf (type id3)
2010-09-03 05:18:13,374 INFO  [STDOUT] [defaultAsyncAction1] 05:18:13,374 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/07a3210e-ed88-4f3e-89b5-c96adea2e5e2 (type id15)
2010-09-03 05:18:13,629 INFO  [STDOUT] [defaultAsyncAction1] 05:18:13,629 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:18:14,257 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's f17b04d5-a57c-4604-bb71-ee534e3e0188 identifier to 64780
2010-09-03 05:18:14,575 INFO  [STDOUT] [defaultAsyncAction1] 05:18:14,575 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/f17b04d5-a57c-4604-bb71-ee534e3e0188 in category1 category MISCELLANEOUS
2010-09-03 05:18:14,575 INFO  [STDOUT] [defaultAsyncAction1] 05:18:14,575 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:18:15,283 INFO  [STDOUT] [defaultAsyncAction1] 05:18:15,283 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/e212bc3b-d268-46b9-84c0-4f93e1c303f7 (type id3)
2010-09-03 05:18:15,302 INFO  [STDOUT] [defaultAsyncAction1] 05:18:15,302 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #3
2010-09-03 05:18:16,056 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's d780719e-f7b3-4a87-9bde-a9fb6632c0ca identifier to 64781
2010-09-03 05:18:16,389 INFO  [STDOUT] [defaultAsyncAction1] 05:18:16,389 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/d780719e-f7b3-4a87-9bde-a9fb6632c0ca in category1 category TKE
2010-09-03 05:18:16,389 INFO  [STDOUT] [defaultAsyncAction1] 05:18:16,389 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:18:17,072 INFO  [STDOUT] [defaultAsyncAction1] 05:18:17,072 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/9abef2f4-aa9b-4003-9175-b1047423f8ae (type id15)
2010-09-03 05:18:17,733 INFO  [STDOUT] [defaultAsyncAction1] 05:18:17,732 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/f3b76395-16a0-4ee7-8666-7af134c9a66b (type id3)
2010-09-03 05:18:18,370 INFO  [STDOUT] [defaultAsyncAction1] 05:18:18,370 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/dce0d3a4-aeec-48e0-a84b-3db8f2dcb7f2 (type id3)
2010-09-03 05:18:18,386 INFO  [STDOUT] [defaultAsyncAction1] 05:18:18,386 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #2
2010-09-03 05:18:19,880 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's d3b34cac-4f22-4a66-8875-867ad69de7d2 identifier to 64782
2010-09-03 05:18:20,219 INFO  [STDOUT] [defaultAsyncAction1] 05:18:20,219 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/d3b34cac-4f22-4a66-8875-867ad69de7d2 in category1 category PE
2010-09-03 05:18:20,220 INFO  [STDOUT] [defaultAsyncAction1] 05:18:20,220 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:true, record:true, cache only:false
2010-09-03 05:18:20,916 INFO  [STDOUT] [defaultAsyncAction1] 05:18:20,916 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/15147c9d-7eab-4e8b-b707-c5ca6e963eae (type id16)
2010-09-03 05:18:20,932 INFO  [STDOUT] [defaultAsyncAction1] 05:18:20,932 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #2
2010-09-03 05:18:21,567 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 66ee0340-2e32-43ab-be2d-c0c153e2f1ed identifier to 64783
2010-09-03 05:18:21,907 INFO  [STDOUT] [defaultAsyncAction1] 05:18:21,907 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/66ee0340-2e32-43ab-be2d-c0c153e2f1ed in category1 category PE
2010-09-03 05:18:21,907 INFO  [STDOUT] [defaultAsyncAction1] 05:18:21,907 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:true, record:true, cache only:false
2010-09-03 05:18:22,627 INFO  [STDOUT] [defaultAsyncAction1] 05:18:22,627 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/fe38c925-62b3-404c-ab90-4fc7c548b816 (type id16)
2010-09-03 05:18:22,643 INFO  [STDOUT] [defaultAsyncAction1] 05:18:22,643 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:18:23,294 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's c4b98868-0ca6-4669-a887-63dcc8f749a5 identifier to 64784
2010-09-03 05:18:23,612 INFO  [STDOUT] [defaultAsyncAction1] 05:18:23,612 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/c4b98868-0ca6-4669-a887-63dcc8f749a5 in category1 category MISCELLANEOUS
2010-09-03 05:18:23,612 INFO  [STDOUT] [defaultAsyncAction1] 05:18:23,612 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:18:24,357 INFO  [STDOUT] [defaultAsyncAction1] 05:18:24,357 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/4bdbe270-2bbf-4148-8a93-91b1995178ee (type id11)
2010-09-03 05:18:25,016 INFO  [STDOUT] [defaultAsyncAction1] 05:18:25,016 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/42046107-eddf-438a-96c4-c423b24f1a98 (type id11)
2010-09-03 05:18:25,031 INFO  [STDOUT] [defaultAsyncAction1] 05:18:25,031 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #2
2010-09-03 05:18:25,926 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's f969bd83-4203-4db4-bc8a-83594a6e507d identifier to 64785
2010-09-03 05:18:26,273 INFO  [STDOUT] [defaultAsyncAction1] 05:18:26,273 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/f969bd83-4203-4db4-bc8a-83594a6e507d in category1 category PE
2010-09-03 05:18:26,273 INFO  [STDOUT] [defaultAsyncAction1] 05:18:26,273 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:true, record:true, cache only:false
2010-09-03 05:18:27,015 INFO  [STDOUT] [defaultAsyncAction1] 05:18:27,015 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/902bdd2d-796e-4a7e-9bd1-096e90b30eac (type id16)
2010-09-03 05:18:27,837 INFO  [STDOUT] [defaultAsyncAction1] 05:18:27,837 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:18:28,348 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 8ef309ad-aa58-4f12-911c-8e29dcf81ed1 identifier to 64786
2010-09-03 05:18:28,670 INFO  [STDOUT] [defaultAsyncAction1] 05:18:28,670 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/8ef309ad-aa58-4f12-911c-8e29dcf81ed1 in category1 category MISCELLANEOUS
2010-09-03 05:18:28,671 INFO  [STDOUT] [defaultAsyncAction1] 05:18:28,671 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:18:29,355 INFO  [STDOUT] [defaultAsyncAction1] 05:18:29,355 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/e19e3a27-764a-4321-ad65-7c5e6ee896fa (type id3)
2010-09-03 05:18:29,452 INFO  [STDOUT] [defaultAsyncAction1] 05:18:29,452 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:18:30,127 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's f6a45e78-3199-4b86-a8b8-aa76b959e750 identifier to 64787
2010-09-03 05:18:30,455 INFO  [STDOUT] [defaultAsyncAction1] 05:18:30,455 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/f6a45e78-3199-4b86-a8b8-aa76b959e750 in category1 category MISCELLANEOUS
2010-09-03 05:18:30,455 INFO  [STDOUT] [defaultAsyncAction1] 05:18:30,455 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:18:31,162 INFO  [STDOUT] [defaultAsyncAction1] 05:18:31,162 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/e1ff0feb-e660-4359-8534-0616e62dcab3 (type id3)
2010-09-03 05:18:31,178 INFO  [STDOUT] [defaultAsyncAction1] 05:18:31,178 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #3
2010-09-03 05:18:31,977 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 5614640e-ab3c-4db1-933a-6d0330d2bd8e identifier to 64788
2010-09-03 05:18:32,333 INFO  [STDOUT] [defaultAsyncAction1] 05:18:32,333 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/5614640e-ab3c-4db1-933a-6d0330d2bd8e in category1 category TKE
2010-09-03 05:18:32,334 INFO  [STDOUT] [defaultAsyncAction1] 05:18:32,334 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:18:33,039 INFO  [STDOUT] [defaultAsyncAction1] 05:18:33,039 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/35455cb5-1c63-4f04-a12c-2e46dce60b41 (type id3)
2010-09-03 05:18:33,708 INFO  [STDOUT] [defaultAsyncAction1] 05:18:33,708 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/2164e69a-db32-4547-b4ea-1056c5fde5db (type id3)
2010-09-03 05:18:34,394 INFO  [STDOUT] [defaultAsyncAction1] 05:18:34,394 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/f771c79d-7207-450b-b6dc-1ec5c934fff6 (type id3)
2010-09-03 05:18:35,079 INFO  [STDOUT] [defaultAsyncAction1] 05:18:35,078 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/da5b1374-47fa-42a2-a241-6bb29ca96b6b (type id3)
2010-09-03 05:18:35,771 INFO  [STDOUT] [defaultAsyncAction1] 05:18:35,771 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/23217d39-a6a7-40a3-86d5-b205300cd852 (type id15)
2010-09-03 05:18:36,474 INFO  [STDOUT] [defaultAsyncAction1] 05:18:36,474 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/926f636b-56fa-44c5-850d-d24e22443bb5 (type id3)
2010-09-03 05:18:37,147 INFO  [STDOUT] [defaultAsyncAction1] 05:18:37,147 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/8992cac3-094e-48b9-95d5-d353f61f073a (type id3)
2010-09-03 05:18:37,164 INFO  [STDOUT] [defaultAsyncAction1] 05:18:37,163 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #2
2010-09-03 05:18:38,189 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's ee16f4f2-4f6f-41a1-8396-da52be1f9805 identifier to 64789
2010-09-03 05:18:38,563 INFO  [STDOUT] [defaultAsyncAction1] 05:18:38,563 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/ee16f4f2-4f6f-41a1-8396-da52be1f9805 in category1 category PE
2010-09-03 05:18:38,563 INFO  [STDOUT] [defaultAsyncAction1] 05:18:38,563 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:true, record:true, cache only:false
2010-09-03 05:18:39,304 INFO  [STDOUT] [defaultAsyncAction1] 05:18:39,304 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/cfe592e7-2142-4472-a5a8-eeded2772833 (type id16)
2010-09-03 05:18:39,320 INFO  [STDOUT] [defaultAsyncAction1] 05:18:39,320 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #2
2010-09-03 05:18:40,731 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 7ba0f9a2-1a9d-445c-8e9c-8aca79299739 identifier to 64790
2010-09-03 05:18:41,107 INFO  [STDOUT] [defaultAsyncAction1] 05:18:41,106 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/7ba0f9a2-1a9d-445c-8e9c-8aca79299739 in category1 category PE
2010-09-03 05:18:41,107 INFO  [STDOUT] [defaultAsyncAction1] 05:18:41,107 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:true, record:true, cache only:false
2010-09-03 05:18:41,860 INFO  [STDOUT] [defaultAsyncAction1] 05:18:41,860 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/90d2b751-b407-4fd2-9ba0-58b0bec1d8a0 (type id16)
2010-09-03 05:18:42,033 INFO  [STDOUT] [defaultAsyncAction1] 05:18:42,033 User:user1@xxx  INFO  [net.company.product.edi.ImportConditional$CountRecords] Found single target record: workspace://SpacesStore/42316a96-d64a-469e-869f-cc64ae8aa81f
2010-09-03 05:18:42,033 INFO  [STDOUT] [defaultAsyncAction1] 05:18:42,033 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #5
2010-09-03 05:18:42,935 INFO  [STDOUT] [defaultAsyncAction1] 05:18:42,935 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/8816253c-4cd5-459f-afe1-e4c9d6d7fb89 (type id3)
2010-09-03 05:18:42,936 INFO  [STDOUT] [defaultAsyncAction1] 05:18:42,936 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #3
2010-09-03 05:18:43,739 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's c3be9bc1-4aba-495d-b745-fc6f130fbde8 identifier to 64791
2010-09-03 05:18:44,114 INFO  [STDOUT] [defaultAsyncAction1] 05:18:44,114 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/c3be9bc1-4aba-495d-b745-fc6f130fbde8 in category1 category TKE
2010-09-03 05:18:44,114 INFO  [STDOUT] [defaultAsyncAction1] 05:18:44,114 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:18:44,873 INFO  [STDOUT] [defaultAsyncAction1] 05:18:44,873 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/8a4b6fd6-5262-4bff-874f-5eba82fede6b (type id15)
2010-09-03 05:18:45,578 INFO  [STDOUT] [defaultAsyncAction1] 05:18:45,578 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/a1387a28-25fc-4f27-88d5-cf457b2ff5f1 (type id3)
2010-09-03 05:18:46,278 INFO  [STDOUT] [defaultAsyncAction1] 05:18:46,278 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/456bc7cb-6cca-4c07-b432-d17de13858da (type id3)
2010-09-03 05:18:46,985 INFO  [STDOUT] [defaultAsyncAction1] 05:18:46,985 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/0ed087de-1c6c-44b5-b3f4-460013d74bb4 (type id3)
2010-09-03 05:18:47,722 INFO  [STDOUT] [defaultAsyncAction1] 05:18:47,722 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/9f050e19-691f-4a8c-9eef-9190961e8504 (type id3)
2010-09-03 05:18:47,739 INFO  [STDOUT] [defaultAsyncAction1] 05:18:47,738 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #3
2010-09-03 05:18:48,691 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's f2eaa06f-92df-423b-910c-1742d3504918 identifier to 64792
2010-09-03 05:18:49,068 INFO  [STDOUT] [defaultAsyncAction1] 05:18:49,068 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/f2eaa06f-92df-423b-910c-1742d3504918 in category1 category VE
2010-09-03 05:18:49,069 INFO  [STDOUT] [defaultAsyncAction1] 05:18:49,069 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:18:49,835 INFO  [STDOUT] [defaultAsyncAction1] 05:18:49,834 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/180400d4-f5f1-42b5-8fc8-729fea839a5d (type id11)
2010-09-03 05:18:49,851 INFO  [STDOUT] [defaultAsyncAction1] 05:18:49,851 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #3
2010-09-03 05:18:51,496 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 565f2391-e77d-473f-836d-0bcdf14cca6b identifier to 64793
2010-09-03 05:18:51,890 INFO  [STDOUT] [defaultAsyncAction1] 05:18:51,890 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/565f2391-e77d-473f-836d-0bcdf14cca6b in category1 category TKE
2010-09-03 05:18:51,891 INFO  [STDOUT] [defaultAsyncAction1] 05:18:51,891 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:18:52,678 INFO  [STDOUT] [defaultAsyncAction1] 05:18:52,677 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/3e24d4e4-38e1-4159-8607-5eddd42a5123 (type id15)
2010-09-03 05:18:53,405 INFO  [STDOUT] [defaultAsyncAction1] 05:18:53,404 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/149157e3-8ebe-43ae-bfdb-e28c04f75a3d (type id72)
2010-09-03 05:18:53,422 INFO  [STDOUT] [defaultAsyncAction1] 05:18:53,422 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #3
2010-09-03 05:18:54,285 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 3a7662fd-2657-46ed-be26-d39980a42cd2 identifier to 64794
2010-09-03 05:18:54,643 INFO  [STDOUT] [defaultAsyncAction1] 05:18:54,643 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/3a7662fd-2657-46ed-be26-d39980a42cd2 in category1 category MISCELLANEOUS
2010-09-03 05:18:54,644 INFO  [STDOUT] [defaultAsyncAction1] 05:18:54,643 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:18:55,423 INFO  [STDOUT] [defaultAsyncAction1] 05:18:55,423 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/66ee970a-4857-49fa-ab3c-89e7487fb867 (type id144)
2010-09-03 05:18:55,440 INFO  [STDOUT] [defaultAsyncAction1] 05:18:55,440 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #2
2010-09-03 05:18:56,310 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's ed82672c-8af1-4eb8-b516-993dc33fa7d2 identifier to 64795
2010-09-03 05:18:56,701 INFO  [STDOUT] [defaultAsyncAction1] 05:18:56,701 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/ed82672c-8af1-4eb8-b516-993dc33fa7d2 in category1 category PE
2010-09-03 05:18:56,702 INFO  [STDOUT] [defaultAsyncAction1] 05:18:56,702 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:true, record:true, cache only:false
2010-09-03 05:18:57,500 INFO  [STDOUT] [defaultAsyncAction1] 05:18:57,500 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/e3fec609-26a4-41da-8c43-e2d0109ffd0b (type id16)
2010-09-03 05:18:57,518 INFO  [STDOUT] [defaultAsyncAction1] 05:18:57,518 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:18:58,194 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's d786af4a-ce1b-4b35-b244-dcc89b065ae8 identifier to 64796
2010-09-03 05:18:58,556 INFO  [STDOUT] [defaultAsyncAction1] 05:18:58,556 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/d786af4a-ce1b-4b35-b244-dcc89b065ae8 in category1 category MISCELLANEOUS
2010-09-03 05:18:58,556 INFO  [STDOUT] [defaultAsyncAction1] 05:18:58,556 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:18:59,365 INFO  [STDOUT] [defaultAsyncAction1] 05:18:59,365 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/6db11235-6af6-42c2-bce6-0058c78c0025 (type id11)
2010-09-03 05:19:00,126 INFO  [STDOUT] [defaultAsyncAction1] 05:19:00,126 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/fb87e682-194b-480d-a083-3d1968bafeb1 (type id11)
2010-09-03 05:19:01,122 INFO  [STDOUT] [defaultAsyncAction1] 05:19:01,122 User:user1@xxx  INFO  [net.company.product.edi.ImportConditional$CountRecords] Found single target record: workspace://SpacesStore/2c9767a0-023a-4d00-aeff-ab70649f697a
2010-09-03 05:19:01,122 INFO  [STDOUT] [defaultAsyncAction1] 05:19:01,122 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #5
2010-09-03 05:19:02,216 INFO  [STDOUT] [defaultAsyncAction1] 05:19:02,216 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/feff83fa-a79e-460a-9f1b-4a4fac21cc16 (type id3)
2010-09-03 05:19:02,365 INFO  [STDOUT] [defaultAsyncAction1] 05:19:02,365 User:user1@xxx  INFO  [net.company.product.edi.ImportConditional$CountRecords] Found single target record: workspace://SpacesStore/491a54c2-8534-45a8-a1a7-49c5812ecbdc
2010-09-03 05:19:02,365 INFO  [STDOUT] [defaultAsyncAction1] 05:19:02,365 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #5
2010-09-03 05:19:03,408 INFO  [STDOUT] [defaultAsyncAction1] 05:19:03,408 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/af394883-66d3-4364-866b-af2aedd1d063 (type id72)
2010-09-03 05:19:04,371 INFO  [STDOUT] [defaultAsyncAction1] 05:19:04,371 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/4c28759c-7361-4cef-9678-978fc2c2e954 (type id3)
2010-09-03 05:19:05,403 INFO  [STDOUT] [defaultAsyncAction1] 05:19:05,403 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/3dbec9a7-31b0-453a-ba9d-ebdd5ff74857 (type id3)
2010-09-03 05:19:06,380 INFO  [STDOUT] [defaultAsyncAction1] 05:19:06,380 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/038a9738-9dbb-417d-a621-818503803ea7 (type id3)
2010-09-03 05:19:07,379 INFO  [STDOUT] [defaultAsyncAction1] 05:19:07,379 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/99dbb469-72a1-4dba-a6bc-015bdce8c7a0 (type id3)
2010-09-03 05:19:08,388 INFO  [STDOUT] [defaultAsyncAction1] 05:19:08,388 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/9a02b1d0-92a3-4707-b9f8-77ca397dd295 (type id3)
2010-09-03 05:19:09,389 INFO  [STDOUT] [defaultAsyncAction1] 05:19:09,389 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/99b73fb8-9883-406d-8653-0224e76707fc (type id3)
2010-09-03 05:19:09,389 INFO  [STDOUT] [defaultAsyncAction1] 05:19:09,389 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #3
2010-09-03 05:19:10,438 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 4252b726-fbdf-410f-8344-1707073adcc4 identifier to 64797
2010-09-03 05:19:10,843 INFO  [STDOUT] [defaultAsyncAction1] 05:19:10,843 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/4252b726-fbdf-410f-8344-1707073adcc4 in category1 category VE
2010-09-03 05:19:10,844 INFO  [STDOUT] [defaultAsyncAction1] 05:19:10,844 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:19:11,707 INFO  [STDOUT] [defaultAsyncAction1] 05:19:11,706 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/d0814aac-5eae-41a2-9761-755dfb3aefbb (type id11)
2010-09-03 05:19:11,881 INFO  [STDOUT] [defaultAsyncAction1] 05:19:11,881 User:user1@xxx  INFO  [net.company.product.edi.ImportConditional$CountRecords] Found single target record: workspace://SpacesStore/7be363d0-d4ee-4e31-80c4-34d0c9c20590
2010-09-03 05:19:11,881 INFO  [STDOUT] [defaultAsyncAction1] 05:19:11,881 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #5
2010-09-03 05:19:12,998 INFO  [STDOUT] [defaultAsyncAction1] 05:19:12,997 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/08cf87d8-303b-4a75-8010-5fe26c5f93bd (type id3)
2010-09-03 05:19:12,998 INFO  [STDOUT] [defaultAsyncAction1] 05:19:12,998 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #3
2010-09-03 05:19:14,799 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 79c84bc6-0150-4189-a9ab-3595ab142cc8 identifier to 64798
2010-09-03 05:19:15,212 INFO  [STDOUT] [defaultAsyncAction1] 05:19:15,212 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/79c84bc6-0150-4189-a9ab-3595ab142cc8 in category1 category VE
2010-09-03 05:19:15,212 INFO  [STDOUT] [defaultAsyncAction1] 05:19:15,212 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:19:16,121 INFO  [STDOUT] [defaultAsyncAction1] 05:19:16,121 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/80b2176e-c9ce-474c-bf85-e635988cfcc7 (type id11)
2010-09-03 05:19:16,257 INFO  [STDOUT] [defaultAsyncAction1] 05:19:16,257 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:19:17,083 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 1ee4c612-c65a-4c54-8a7d-6c55d2b869b3 identifier to 64799
2010-09-03 05:19:17,482 INFO  [STDOUT] [defaultAsyncAction1] 05:19:17,481 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/1ee4c612-c65a-4c54-8a7d-6c55d2b869b3 in category1 category MISCELLANEOUS
2010-09-03 05:19:17,482 INFO  [STDOUT] [defaultAsyncAction1] 05:19:17,482 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:19:18,358 INFO  [STDOUT] [defaultAsyncAction1] 05:19:18,357 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/ee833319-4fbc-471b-a32c-33836a500223 (type id3)
2010-09-03 05:19:18,376 INFO  [STDOUT] [defaultAsyncAction1] 05:19:18,376 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Executing rule #6
2010-09-03 05:19:19,274 INFO  [STDOUT] [defaultAsyncAction1] onCreateRecord(): set record's 83135132-cfb0-4f87-9ffb-6916c12c81aa identifier to 64800
2010-09-03 05:19:19,674 INFO  [STDOUT] [defaultAsyncAction1] 05:19:19,674 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$CreateRecord] Created record workspace://SpacesStore/83135132-cfb0-4f87-9ffb-6916c12c81aa in category1 category MISCELLANEOUS
2010-09-03 05:19:19,674 INFO  [STDOUT] [defaultAsyncAction1] 05:19:19,674 User:user1@xxx  INFO  [net.company.product.edi.ImportOperation$XXXQuery] Triggering XXX Query for - attachments:false, record:true, cache only:false
2010-09-03 05:19:20,582 INFO  [STDOUT] [defaultAsyncAction1] 05:19:20,582 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/d81b3692-3e00-4741-95a2-36a4d076f131 (type id11)
2010-09-03 05:19:21,405 INFO  [STDOUT] [defaultAsyncAction1] 05:19:21,405 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/1ef761f9-ab26-46a9-9221-e3e673e9eff4 (type id11)
2010-09-03 05:19:22,216 INFO  [STDOUT] [defaultAsyncAction1] 05:19:22,216 User:user1@xxx  INFO  [net.company.product.edi.ImportProcessor] Created attachment workspace://SpacesStore/bc9dbed1-e5bf-4a24-a6d2-58aa25d15c23 (type id11)
2010-09-03 05:19:22,818 INFO  [STDOUT] [defaultAsyncAction1] 05:19:22,818 User:user1@xxx  INFO  [net.company.product.edi.ImporterWrapper] ImportProcessor> Import of …/user1/D.31AB475A.20100903.INDX.zip ended in 141979ms
2010-09-03 05:30:01,166 INFO  [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: starting /xxx/check.seam
2010-09-03 05:30:01,329 INFO  [STDOUT] [RMI TCP Connection(436)-192.168.129.59] 05:30:01,329 Tenant:xxx User:admin INFO  [net.company.product.service.edi.SpoolServiceImpl] Creating empty file <f5-check.tmp-5b8e2216-e6c1-4441-b4ed-9ea08969f5ed> in spool <workspace://SpacesStore/6f956092-cbbb-4be0-8952-a12601cd191d>.
2010-09-03 05:30:01,454 INFO  User:admin@xxx [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: finished /xxx/check.seam in 288ms
2010-09-03 05:47:04,146 INFO  [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: starting /xxx/check.seam
2010-09-03 05:47:04,226 INFO  [STDOUT] [RMI TCP Connection(468)-192.168.129.59] 05:47:04,226 Tenant:xxx User:admin INFO  [net.company.product.service.edi.SpoolServiceImpl] Creating empty file <f5-check.tmp-522ddc5c-748e-4fdb-b95e-b73235fb032b> in spool <workspace://SpacesStore/6f956092-cbbb-4be0-8952-a12601cd191d>.
2010-09-03 05:47:04,354 INFO  User:admin@xxx [com.company.application.filters.PerformanceLogFilter] [http-192.168.129.59-8080-2] X-Forwarded-For 194.215.209.127: finished /xxx/check.seam in 208ms
2010-09-03 05:55:45,092 INFO  [STDOUT] [DefaultScheduler_Worker-3] 05:55:45,090  ERROR [org.quartz.core.JobRunShell] Job DEFAULT.userUsageTrackingJobDetail threw an unhandled Exception:
org.springframework.dao.CannotAcquireLockException: Hibernate operation: could not execute update query; SQL [delete from alf_usage_delta where node_id=?]; Lock wait timeout exceeded; try restarting transaction; nested exception is java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction
Caused by: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction
   at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:946)
   at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:2870)
   at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1573)
   at com.mysql.jdbc.ServerPreparedStatement.serverExecute(ServerPreparedStatement.java:1169)
   at com.mysql.jdbc.ServerPreparedStatement.executeInternal(ServerPreparedStatement.java:693)
   at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1404)
   at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1318)
   at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1303)
   at org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:101)
   at org.hibernate.hql.ast.exec.BasicExecutor.execute(BasicExecutor.java:75)
   at org.hibernate.hql.ast.QueryTranslatorImpl.executeUpdate(QueryTranslatorImpl.java:396)
   at org.hibernate.engine.query.HQLQueryPlan.performExecuteUpdate(HQLQueryPlan.java:259)
   at org.hibernate.impl.SessionImpl.executeUpdate(SessionImpl.java:1141)
   at org.hibernate.impl.QueryImpl.executeUpdate(QueryImpl.java:94)
   at org.alfresco.repo.domain.hibernate.HibernateUsageDeltaDAO$2.doInHibernate(HibernateUsageDeltaDAO.java:161)
   at org.springframework.orm.hibernate3.HibernateTcategory3ate.execute(HibernateTcategory3ate.java:372)
   at org.springframework.orm.hibernate3.HibernateTcategory3ate.execute(HibernateTcategory3ate.java:338)
   at org.alfresco.repo.domain.hibernate.HibernateUsageDeltaDAO.deleteDeltas(HibernateUsageDeltaDAO.java:166)
   at org.alfresco.repo.domain.hibernate.HibernateUsageDeltaDAO.deleteDeltas(HibernateUsageDeltaDAO.java:149)
   at org.alfresco.repo.usage.UsageServiceImpl.deleteDeltas(UsageServiceImpl.java:65)
   at sun.reflect.GeneratedMethodAccessor660.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:597)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:304)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
   at org.alfresco.repo.tenant.MultiTNodeServiceInterceptor.invoke(MultiTNodeServiceInterceptor.java:167)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
   at $Proxy99.deleteDeltas(Unknown Source)
   at org.alfresco.repo.usage.UserUsageTrackingComponent$9.execute(UserUsageTrackingComponent.java:558)
   at org.alfresco.repo.usage.UserUsageTrackingComponent$9.execute(UserUsageTrackingComponent.java:539)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:322)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:248)
   at org.alfresco.repo.usage.UserUsageTrackingComponent.collapseUsage(UserUsageTrackingComponent.java:579)
   at org.alfresco.repo.usage.UserUsageTrackingComponent.access$600(UserUsageTrackingComponent.java:60)
   at org.alfresco.repo.usage.UserUsageTrackingComponent$8.doWork(UserUsageTrackingComponent.java:519)
   at org.alfresco.repo.usage.UserUsageTrackingComponent$8.doWork(UserUsageTrackingComponent.java:517)
   at org.alfresco.repo.security.authentication.AuthenticationUtil.runAs(AuthenticationUtil.java:489)
   at org.alfresco.repo.usage.UserUsageTrackingComponent.collapseUsages(UserUsageTrackingComponent.java:515)
   at org.alfresco.repo.usage.UserUsageTrackingComponent.execute(UserUsageTrackingComponent.java:143)
   at org.alfresco.repo.usage.UserUsageCollapseJob.execute(UserUsageCollapseJob.java:48)
   at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
   at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)
2010-09-03 05:55:45,093 INFO  [STDOUT] [DefaultScheduler_Worker-3] 05:55:45,092  ERROR [org.quartz.core.ErrorLogger] Job (DEFAULT.userUsageTrackingJobDetail threw an exception.
org.quartz.SchedulerException: Job threw an unhandled exception. [See nested exception: org.springframework.dao.CannotAcquireLockException: Hibernate operation: could not execute update query; SQL [delete from alf_usage_delta where node_id=?]; Lock wait timeout exceeded; try restarting transaction; nested exception is java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction]
   at org.quartz.core.JobRunShell.run(JobRunShell.java:213)
   at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)
Caused by: org.springframework.dao.CannotAcquireLockException: Hibernate operation: could not execute update query; SQL [delete from alf_usage_delta where node_id=?]; Lock wait timeout exceeded; try restarting transaction; nested exception is java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction
   at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.translate(SQLErrorCodeSQLExceptionTranslator.java:250)
   at org.springframework.orm.hibernate3.HibernateAccessor.convertJdbcAccessException(HibernateAccessor.java:424)
   at org.springframework.orm.hibernate3.HibernateAccessor.convertHibernateAccessException(HibernateAccessor.java:410)
   at org.springframework.orm.hibernate3.HibernateTcategory3ate.execute(HibernateTcategory3ate.java:377)
   at org.springframework.orm.hibernate3.HibernateTcategory3ate.execute(HibernateTcategory3ate.java:338)
   at org.alfresco.repo.domain.hibernate.HibernateUsageDeltaDAO.deleteDeltas(HibernateUsageDeltaDAO.java:166)
   at org.alfresco.repo.domain.hibernate.HibernateUsageDeltaDAO.deleteDeltas(HibernateUsageDeltaDAO.java:149)
   at org.alfresco.repo.usage.UsageServiceImpl.deleteDeltas(UsageServiceImpl.java:65)
   at sun.reflect.GeneratedMethodAccessor660.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:597)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:304)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
   at org.alfresco.repo.tenant.MultiTNodeServiceInterceptor.invoke(MultiTNodeServiceInterceptor.java:167)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
   at $Proxy99.deleteDeltas(Unknown Source)
   at org.alfresco.repo.usage.UserUsageTrackingComponent$9.execute(UserUsageTrackingComponent.java:558)
   at org.alfresco.repo.usage.UserUsageTrackingComponent$9.execute(UserUsageTrackingComponent.java:539)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:322)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:248)
   at org.alfresco.repo.usage.UserUsageTrackingComponent.collapseUsage(UserUsageTrackingComponent.java:579)
   at org.alfresco.repo.usage.UserUsageTrackingComponent.access$600(UserUsageTrackingComponent.java:60)
   at org.alfresco.repo.usage.UserUsageTrackingComponent$8.doWork(UserUsageTrackingComponent.java:519)
   at org.alfresco.repo.usage.UserUsageTrackingComponent$8.doWork(UserUsageTrackingComponent.java:517)
   at org.alfresco.repo.security.authentication.AuthenticationUtil.runAs(AuthenticationUtil.java:489)
   at org.alfresco.repo.usage.UserUsageTrackingComponent.collapseUsages(UserUsageTrackingComponent.java:515)
   at org.alfresco.repo.usage.UserUsageTrackingComponent.execute(UserUsageTrackingComponent.java:143)
   at org.alfresco.repo.usage.UserUsageCollapseJob.execute(UserUsageCollapseJob.java:48)
   at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
   … 1 more
Caused by: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction
   at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:946)
   at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:2870)
   at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1573)
   at com.mysql.jdbc.ServerPreparedStatement.serverExecute(ServerPreparedStatement.java:1169)
   at com.mysql.jdbc.ServerPreparedStatement.executeInternal(ServerPreparedStatement.java:693)
   at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1404)
   at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1318)
   at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1303)
   at org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:101)
   at org.hibernate.hql.ast.exec.BasicExecutor.execute(BasicExecutor.java:75)
   at org.hibernate.hql.ast.QueryTranslatorImpl.executeUpdate(QueryTranslatorImpl.java:396)
   at org.hibernate.engine.query.HQLQueryPlan.performExecuteUpdate(HQLQueryPlan.java:259)
   at org.hibernate.impl.SessionImpl.executeUpdate(SessionImpl.java:1141)
   at org.hibernate.impl.QueryImpl.executeUpdate(QueryImpl.java:94)
   at org.alfresco.repo.domain.hibernate.HibernateUsageDeltaDAO$2.doInHibernate(HibernateUsageDeltaDAO.java:161)
   at org.springframework.orm.hibernate3.HibernateTcategory3ate.execute(HibernateTemplate.java:372)
   … 28 more

Outcomes