15 Feb 2013 15:32:44,004 WARN CacheManager,load initial:459 - Creating a new instance of CacheManager using the diskStorePath "C:\Users\Tim\AppData\Local\Temp\" which is already used by an existing CacheManager. The source of the configuration was classpath. The diskStore path for this CacheManager will be set to C:\Users\Tim\AppData\Local\Temp\\ehcache_auto_created_1360902764004. To avoid this warning consider using the CacheManager factory methods to create a singleton CacheManager or specifying a separate ehcache configuration (ehcache.xml) for each CacheManager instance. 15 Feb 2013 15:46:47,332 ERROR LoaderPlugin,Patient-Client.0 (Thread-422):229 - Failed to process row T1: Failed to retrieve object: P-9999 org.openvpms.etl.load.LoaderException: Failed to retrieve object: P-9999 at org.openvpms.etl.load.DefaultObjectHandler.getMappedReference(DefaultObjectHandler.java:443) at org.openvpms.etl.load.DefaultObjectHandler.getReference(DefaultObjectHandler.java:293) at org.openvpms.etl.load.RowMapper.mapValue(RowMapper.java:194) at org.openvpms.etl.load.RowMapper.map(RowMapper.java:161) at org.openvpms.etl.load.Loader.load(Loader.java:115) at org.openvpms.etl.kettle.LoaderAdapter.load(LoaderAdapter.java:110) at org.openvpms.etl.kettle.LoaderPlugin.processRow(LoaderPlugin.java:118) at org.openvpms.etl.kettle.LoaderPlugin.run(LoaderPlugin.java:187) 15 Feb 2013 15:46:47,332 ERROR LoaderPlugin,Patient-Client.0 (Thread-422):229 - Failed to process row T1: Failed to retrieve object: P-9999 org.openvpms.etl.load.LoaderException: Failed to retrieve object: P-9999 at org.openvpms.etl.load.DefaultObjectHandler.getMappedReference(DefaultObjectHandler.java:443) at org.openvpms.etl.load.DefaultObjectHandler.getReference(DefaultObjectHandler.java:293) at org.openvpms.etl.load.RowMapper.mapValue(RowMapper.java:194) at org.openvpms.etl.load.RowMapper.map(RowMapper.java:161) at org.openvpms.etl.load.Loader.load(Loader.java:115) at org.openvpms.etl.kettle.LoaderAdapter.load(LoaderAdapter.java:110) at org.openvpms.etl.kettle.LoaderPlugin.processRow(LoaderPlugin.java:118) at org.openvpms.etl.kettle.LoaderPlugin.run(LoaderPlugin.java:187) 15 Feb 2013 15:48:10,817 ERROR LoaderPlugin,appointment.0 (Thread-444):235 - Failed to process: Invalid argument 'archetypeId' org.openvpms.component.business.service.archetype.ArchetypeServiceException: Failed to save a collection of 1,001 objects. at org.openvpms.component.business.service.archetype.ArchetypeService.save(ArchetypeService.java:545) at org.openvpms.component.business.service.archetype.ArchetypeService.save(ArchetypeService.java:513) at org.openvpms.etl.load.DefaultObjectHandler.save(DefaultObjectHandler.java:325) at org.openvpms.etl.load.DefaultObjectHandler.save(DefaultObjectHandler.java:390) at org.openvpms.etl.load.DefaultObjectHandler.commit(DefaultObjectHandler.java:173) at org.openvpms.etl.load.Loader.load(Loader.java:121) at org.openvpms.etl.kettle.LoaderAdapter.load(LoaderAdapter.java:110) at org.openvpms.etl.kettle.LoaderPlugin.processRow(LoaderPlugin.java:118) at org.openvpms.etl.kettle.LoaderPlugin.run(LoaderPlugin.java:187) Caused by: org.openvpms.component.business.dao.im.common.IMObjectDAOException: Failed to save a collection of objects at org.openvpms.component.business.dao.hibernate.im.IMObjectDAOHibernate.save(IMObjectDAOHibernate.java:191) at org.openvpms.component.business.service.archetype.ArchetypeService.save(ArchetypeService.java:542) ... 8 more Caused by: java.lang.IllegalArgumentException: Invalid argument 'archetypeId' at org.openvpms.component.business.domain.im.common.IMObjectReference.(IMObjectReference.java:111) at org.openvpms.component.business.dao.hibernate.im.common.IMObjectDOImpl.getObjectReference(IMObjectDOImpl.java:180) at org.openvpms.component.business.dao.hibernate.im.common.IMObjectDOImpl.equals(IMObjectDOImpl.java:329) at java.util.HashMap.put(Unknown Source) at org.openvpms.component.business.dao.hibernate.im.common.Context.add(Context.java:262) at org.openvpms.component.business.dao.hibernate.im.common.IMObjectAssembler.assemble(IMObjectAssembler.java:109) at org.openvpms.component.business.dao.hibernate.im.common.CompoundAssembler.assemble(CompoundAssembler.java:90) at org.openvpms.component.business.dao.hibernate.im.common.AbstractAssembler.getDO(AbstractAssembler.java:50) at org.openvpms.component.business.dao.hibernate.im.common.SetAssembler.assembleDO(SetAssembler.java:114) at org.openvpms.component.business.dao.hibernate.im.act.AbstractActAssembler.assembleDO(AbstractActAssembler.java:91) at org.openvpms.component.business.dao.hibernate.im.act.AbstractActAssembler.assembleDO(AbstractActAssembler.java:39) at org.openvpms.component.business.dao.hibernate.im.common.IMObjectAssembler.assemble(IMObjectAssembler.java:113) at org.openvpms.component.business.dao.hibernate.im.common.CompoundAssembler.assemble(CompoundAssembler.java:90) at org.openvpms.component.business.dao.hibernate.im.IMObjectDAOHibernate.save(IMObjectDAOHibernate.java:879) at org.openvpms.component.business.dao.hibernate.im.IMObjectDAOHibernate.save(IMObjectDAOHibernate.java:897) at org.openvpms.component.business.dao.hibernate.im.IMObjectDAOHibernate.access$100(IMObjectDAOHibernate.java:98) at org.openvpms.component.business.dao.hibernate.im.IMObjectDAOHibernate$2.doInHibernate(IMObjectDAOHibernate.java:186) at org.springframework.orm.hibernate3.HibernateTemplate.doExecute(HibernateTemplate.java:406) at org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:339) at org.openvpms.component.business.dao.hibernate.im.IMObjectDAOHibernate$9$1.doInHibernate(IMObjectDAOHibernate.java:1086) at org.springframework.orm.hibernate3.HibernateTemplate.doExecute(HibernateTemplate.java:406) at org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:339) at org.openvpms.component.business.dao.hibernate.im.IMObjectDAOHibernate$9.doInTransaction(IMObjectDAOHibernate.java:1082) at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:130) at org.openvpms.component.business.dao.hibernate.im.IMObjectDAOHibernate.update(IMObjectDAOHibernate.java:1080) at org.openvpms.component.business.dao.hibernate.im.IMObjectDAOHibernate.save(IMObjectDAOHibernate.java:183) ... 9 more 15 Feb 2013 15:48:10,817 ERROR LoaderPlugin,appointment.0 (Thread-444):235 - Failed to process: Invalid argument 'archetypeId' org.openvpms.component.business.service.archetype.ArchetypeServiceException: Failed to save a collection of 1,001 objects. at org.openvpms.component.business.service.archetype.ArchetypeService.save(ArchetypeService.java:545) at org.openvpms.component.business.service.archetype.ArchetypeService.save(ArchetypeService.java:513) at org.openvpms.etl.load.DefaultObjectHandler.save(DefaultObjectHandler.java:325) at org.openvpms.etl.load.DefaultObjectHandler.save(DefaultObjectHandler.java:390) at org.openvpms.etl.load.DefaultObjectHandler.commit(DefaultObjectHandler.java:173) at org.openvpms.etl.load.Loader.load(Loader.java:121) at org.openvpms.etl.kettle.LoaderAdapter.load(LoaderAdapter.java:110) at org.openvpms.etl.kettle.LoaderPlugin.processRow(LoaderPlugin.java:118) at org.openvpms.etl.kettle.LoaderPlugin.run(LoaderPlugin.java:187) Caused by: org.openvpms.component.business.dao.im.common.IMObjectDAOException: Failed to save a collection of objects at org.openvpms.component.business.dao.hibernate.im.IMObjectDAOHibernate.save(IMObjectDAOHibernate.java:191) at org.openvpms.component.business.service.archetype.ArchetypeService.save(ArchetypeService.java:542) ... 8 more Caused by: java.lang.IllegalArgumentException: Invalid argument 'archetypeId' at org.openvpms.component.business.domain.im.common.IMObjectReference.(IMObjectReference.java:111) at org.openvpms.component.business.dao.hibernate.im.common.IMObjectDOImpl.getObjectReference(IMObjectDOImpl.java:180) at org.openvpms.component.business.dao.hibernate.im.common.IMObjectDOImpl.equals(IMObjectDOImpl.java:329) at java.util.HashMap.put(Unknown Source) at org.openvpms.component.business.dao.hibernate.im.common.Context.add(Context.java:262) at org.openvpms.component.business.dao.hibernate.im.common.IMObjectAssembler.assemble(IMObjectAssembler.java:109) at org.openvpms.component.business.dao.hibernate.im.common.CompoundAssembler.assemble(CompoundAssembler.java:90) at org.openvpms.component.business.dao.hibernate.im.common.AbstractAssembler.getDO(AbstractAssembler.java:50) at org.openvpms.component.business.dao.hibernate.im.common.SetAssembler.assembleDO(SetAssembler.java:114) at org.openvpms.component.business.dao.hibernate.im.act.AbstractActAssembler.assembleDO(AbstractActAssembler.java:91) at org.openvpms.component.business.dao.hibernate.im.act.AbstractActAssembler.assembleDO(AbstractActAssembler.java:39) at org.openvpms.component.business.dao.hibernate.im.common.IMObjectAssembler.assemble(IMObjectAssembler.java:113) at org.openvpms.component.business.dao.hibernate.im.common.CompoundAssembler.assemble(CompoundAssembler.java:90) at org.openvpms.component.business.dao.hibernate.im.IMObjectDAOHibernate.save(IMObjectDAOHibernate.java:879) at org.openvpms.component.business.dao.hibernate.im.IMObjectDAOHibernate.save(IMObjectDAOHibernate.java:897) at org.openvpms.component.business.dao.hibernate.im.IMObjectDAOHibernate.access$100(IMObjectDAOHibernate.java:98) at org.openvpms.component.business.dao.hibernate.im.IMObjectDAOHibernate$2.doInHibernate(IMObjectDAOHibernate.java:186) at org.springframework.orm.hibernate3.HibernateTemplate.doExecute(HibernateTemplate.java:406) at org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:339) at org.openvpms.component.business.dao.hibernate.im.IMObjectDAOHibernate$9$1.doInHibernate(IMObjectDAOHibernate.java:1086) at org.springframework.orm.hibernate3.HibernateTemplate.doExecute(HibernateTemplate.java:406) at org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:339) at org.openvpms.component.business.dao.hibernate.im.IMObjectDAOHibernate$9.doInTransaction(IMObjectDAOHibernate.java:1082) at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:130) at org.openvpms.component.business.dao.hibernate.im.IMObjectDAOHibernate.update(IMObjectDAOHibernate.java:1080) at org.openvpms.component.business.dao.hibernate.im.IMObjectDAOHibernate.save(IMObjectDAOHibernate.java:183) ... 9 more Kettle log for the transform that cause the above error 2013/02/15 15:47:57 - load Clipboard - Starting entry [Rx Appointment] 2013/02/15 15:47:57 - Rx Appointment - Loading transformation from XML file [file:///C:/Kettle/opv/Rx_Appointment_100.ktr] 2013/02/15 15:47:57 - Rx Appointment - Dispatching started for transformation [Rx Appointment] 2013/02/15 15:47:57 - Rx Appointment - This transformation can be replayed with replay date: 2013/02/15 15:47:57 2013/02/15 15:47:57 - Map Clipboard.0 - Reading lookup values from step [mapClipAppts.csv] 2013/02/15 15:47:57 - Xlate ApptType.0 - Reading lookup values from step [xlateApptType.csv] 2013/02/15 15:47:57 - flag Missing.0 - Reading lookup values from step [missingPatients.csv] 2013/02/15 15:47:57 - xlateApptType.csv.0 - Header row skipped in file '/Kettle/opv/xlateApptType.csv' 2013/02/15 15:47:57 - mapClipAppts.csv.0 - Header row skipped in file '/Kettle/opv/mapClipAppts.csv' 2013/02/15 15:47:57 - appointment.0 - Starting... 2013/02/15 15:47:57 - mapClipAppts.csv.0 - Finished processing (I=8, O=0, R=0, W=7, U=0, E=0) 2013/02/15 15:47:57 - xlateApptType.csv.0 - Finished processing (I=13, O=0, R=0, W=12, U=0, E=0) 2013/02/15 15:47:57 - missingPatients.csv.0 - Header row skipped in file '/Kettle/opv/missingPatients.csv' 2013/02/15 15:47:57 - missingPatients.csv.0 - Finished processing (I=50, O=0, R=0, W=49, U=0, E=0) 2013/02/15 15:47:58 - RxW Clipboard.0 - linenr 5000 2013/02/15 15:47:58 - Select values.0 - linenr 5000 2013/02/15 15:48:00 - Map Clipboard.0 - linenr 5000 2013/02/15 15:48:08 - flag Missing.0 - linenr 5000 2013/02/15 15:48:10 - appointment.0 - Failed to process: Invalid argument 'archetypeId' 2013/02/15 15:48:19 - Xlate ApptType.0 - linenr 5000 2013/02/15 15:48:27 - RxW Clipboard.0 - linenr 10000 2013/02/15 15:48:27 - Process.0 - linenr 5000 2013/02/15 15:48:35 - Select values.0 - linenr 10000 2013/02/15 15:48:35 - test.csv.0 - linenr 5000 2013/02/15 15:48:35 - appointment.0 - Processed 5000 rows... 2013/02/15 15:48:42 - Map Clipboard.0 - linenr 10000 2013/02/15 15:48:49 - flag Missing.0 - linenr 10000 2013/02/15 15:48:57 - Xlate ApptType.0 - linenr 10000 2013/02/15 15:49:05 - RxW Clipboard.0 - linenr 15000 2013/02/15 15:49:05 - Process.0 - linenr 10000 2013/02/15 15:49:12 - Select values.0 - linenr 15000 2013/02/15 15:49:12 - test.csv.0 - linenr 10000 2013/02/15 15:49:12 - appointment.0 - Processed 10000 rows... 2013/02/15 15:49:19 - Map Clipboard.0 - linenr 15000 2013/02/15 15:49:26 - flag Missing.0 - linenr 15000 2013/02/15 15:49:34 - Xlate ApptType.0 - linenr 15000 2013/02/15 15:49:41 - RxW Clipboard.0 - linenr 20000 2013/02/15 15:49:41 - Process.0 - linenr 15000 2013/02/15 15:49:48 - Select values.0 - linenr 20000 2013/02/15 15:49:48 - test.csv.0 - linenr 15000 2013/02/15 15:49:48 - appointment.0 - Processed 15000 rows... 2013/02/15 15:49:55 - Map Clipboard.0 - linenr 20000 2013/02/15 15:50:02 - flag Missing.0 - linenr 20000 2013/02/15 15:50:10 - Xlate ApptType.0 - linenr 20000 2013/02/15 15:50:17 - RxW Clipboard.0 - linenr 25000 2013/02/15 15:50:17 - Process.0 - linenr 20000 2013/02/15 15:50:24 - Select values.0 - linenr 25000 2013/02/15 15:50:24 - test.csv.0 - linenr 20000 2013/02/15 15:50:24 - appointment.0 - Processed 20000 rows... 2013/02/15 15:50:32 - Map Clipboard.0 - linenr 25000 2013/02/15 15:50:39 - flag Missing.0 - linenr 25000 2013/02/15 15:50:46 - Xlate ApptType.0 - linenr 25000 2013/02/15 15:50:54 - RxW Clipboard.0 - linenr 30000 2013/02/15 15:50:54 - Process.0 - linenr 25000 2013/02/15 15:51:01 - Select values.0 - linenr 30000 2013/02/15 15:51:01 - test.csv.0 - linenr 25000 2013/02/15 15:51:01 - appointment.0 - Processed 25000 rows... 2013/02/15 15:51:09 - Map Clipboard.0 - linenr 30000 2013/02/15 15:51:16 - flag Missing.0 - linenr 30000 2013/02/15 15:51:23 - Xlate ApptType.0 - linenr 30000 2013/02/15 15:51:30 - RxW Clipboard.0 - linenr 35000 2013/02/15 15:51:30 - Process.0 - linenr 30000 2013/02/15 15:51:38 - Select values.0 - linenr 35000 2013/02/15 15:51:38 - test.csv.0 - linenr 30000 2013/02/15 15:51:38 - appointment.0 - Processed 30000 rows... 2013/02/15 15:51:45 - Map Clipboard.0 - linenr 35000 2013/02/15 15:51:52 - flag Missing.0 - linenr 35000 2013/02/15 15:51:59 - Xlate ApptType.0 - linenr 35000 2013/02/15 15:52:05 - RxW Clipboard.0 - Finished reading query, closing connection. 2013/02/15 15:52:05 - RxW Clipboard.0 - Finished processing (I=39117, O=0, R=0, W=39117, U=0, E=0) 2013/02/15 15:52:06 - Process.0 - linenr 35000 2013/02/15 15:52:12 - Select values.0 - Finished processing (I=0, O=0, R=39117, W=39117, U=0, E=0) 2013/02/15 15:52:13 - test.csv.0 - linenr 35000 2013/02/15 15:52:13 - appointment.0 - Processed 35000 rows... 2013/02/15 15:52:19 - Map Clipboard.0 - Finished processing (I=0, O=0, R=39124, W=39117, U=0, E=0) 2013/02/15 15:52:26 - flag Missing.0 - Finished processing (I=0, O=0, R=39166, W=39117, U=0, E=0) 2013/02/15 15:52:33 - Xlate ApptType.0 - Finished processing (I=0, O=0, R=39129, W=39117, U=0, E=0) 2013/02/15 15:52:41 - Process.0 - Finished processing (I=0, O=0, R=39117, W=39117, U=0, E=0) 2013/02/15 15:52:47 - test.csv.0 - Finished processing (I=0, O=39118, R=39117, W=39117, U=0, E=0) 2013/02/15 15:52:48 - appointment.0 - Processed 39117 rows in 290.5 seconds ( 134.6 rows/sec), generating 244341 objects (840.9 objects/sec)