SQL Power Software Forum

os: vista
db: oracle
dqguru version: 0.9.6-alpha

Created merge rules and marked one pair of records as a match. In debug mode, ran the engine.

Error during engine run
java.lang.RuntimeException: java.lang.NullPointerException
at ca.sqlpower.matchmaker.MergeEngineImpl.call(MergeEngineImpl.java:193)
at ca.sqlpower.matchmaker.swingui.engine.EngineWorker.doStuff(EngineWorker.java:117)
at ca.sqlpower.swingui.SPSwingWorker.run(SPSwingWorker.java:99)
at java.lang.Thread.run(Unknown Source)
Caused by: java.lang.NullPointerException
at ca.sqlpower.matchmaker.TableMergeRules.getUniqueKeyColumns(TableMergeRules.java:479)
at ca.sqlpower.matchmaker.MergeProcessor.generateUKWhereStatement(MergeProcessor.java:999)
at ca.sqlpower.matchmaker.MergeProcessor.findRowByUniqueKey(MergeProcessor.java:897)
at ca.sqlpower.matchmaker.MergeProcessor.call(MergeProcessor.java:183)
at ca.sqlpower.matchmaker.MergeEngineImpl.call(MergeEngineImpl.java:167)
... 3 more

Below is the log file:

2009-06-01 13:27:58,731 DEBUG Deleting duplicate's child records on table PHARMA_DW.PRODUCT_BUDGET (TABLE)
2009-06-01 13:28:07,877 DEBUG Child table RETAIL_ACQUISITION has 0 child records
2009-06-01 13:28:07,878 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:28:07,880 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.RETAIL_ACQUISITION (TABLE)
2009-06-01 13:28:07,881 DEBUG Merging duplicate's child records on table PHARMA_DW.RETAIL_ACQUISITION (TABLE)
2009-06-01 13:28:07,882 DEBUG Deleting duplicate's child records on table PHARMA_DW.RETAIL_ACQUISITION (TABLE)
2009-06-01 13:28:09,623 DEBUG Child table ORDER_LINE has 0 child records
2009-06-01 13:28:09,625 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:28:09,626 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.ORDER_LINE (TABLE)
2009-06-01 13:28:09,629 DEBUG Merging duplicate's child records on table PHARMA_DW.ORDER_LINE (TABLE)
2009-06-01 13:28:09,630 DEBUG Deleting duplicate's child records on table PHARMA_DW.ORDER_LINE (TABLE)
2009-06-01 13:28:09,645 DEBUG Child table PRODUCT_XREF has 1 child records
2009-06-01 13:28:09,650 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:28:09,654 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.PRODUCT_XREF (TABLE)
2009-06-01 13:28:09,682 DEBUG generatePKWhereStatement returns:
WHERE LEGACY_SOURCE_ID='SAMPLE DATA' AND LEGACY_PRODUCT_ID='68443'
2009-06-01 13:28:09,684 DEBUG MergeProcessor.updateRow is executing the SQL statement:
UPDATE PHARMA_DW.PRODUCT_XREF SET
DW_PRODUCT_ID=2067,
LAST_UPDATE_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS'),
LAST_UPDATE_USER='PL'
WHERE LEGACY_SOURCE_ID='SAMPLE DATA' AND LEGACY_PRODUCT_ID='68443'
2009-06-01 13:28:09,689 DEBUG Modified 1 row(s) of PHARMA_DW.PRODUCT_XREF
2009-06-01 13:28:09,690 DEBUG Merging duplicate's child records on table PHARMA_DW.PRODUCT_XREF (TABLE)
2009-06-01 13:28:09,691 DEBUG Merging child records of PRODUCT_XREF ...
2009-06-01 13:28:09,693 DEBUG Duplicate: [SAMPLE DATA, 68443, 6, 2009-05-25, PL]; Master: [SAMPLE DATA, 68443, 2067, 2009-05-25, PL]
2009-06-01 13:28:09,694 DEBUG Finished merging on table PRODUCT_XREF
2009-06-01 13:28:09,697 DEBUG Deleting duplicate's child records on table PHARMA_DW.PRODUCT_XREF (TABLE)
2009-06-01 13:28:09,747 DEBUG Child table PRODUCT_PRICE has 1 child records
2009-06-01 13:28:09,748 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:28:09,750 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.PRODUCT_PRICE (TABLE)
2009-06-01 13:28:09,794 DEBUG Inserted 1 row(s) into PHARMA_DW.PRODUCT_PRICE
2009-06-01 13:28:09,795 DEBUG Merging duplicate's child records on table PHARMA_DW.PRODUCT_PRICE (TABLE)
2009-06-01 13:28:09,795 DEBUG Merging child records of PRODUCT_PRICE ...
2009-06-01 13:28:09,797 DEBUG Duplicate: [6, UNKNOWN, 2009-05-25, 0, null, SAMPLE DATA, 2009-05-25, PL]; Master: [2067, UNKNOWN, 2009-05-25, 0, null, SAMPLE DATA, 2009-05-25, PL]
2009-06-01 13:28:09,797 DEBUG Finished merging on table PRODUCT_PRICE
2009-06-01 13:28:09,798 DEBUG Deleting duplicate's child records on table PHARMA_DW.PRODUCT_PRICE (TABLE)
2009-06-01 13:28:09,799 DEBUG DELETE FROM PHARMA_DW.PRODUCT_PRICE
WHERE PRODUCT_ID=6 AND MARKET_SEGMENT_TYPE='UNKNOWN' AND PERIOD_START_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS')
2009-06-01 13:28:09,803 DEBUG Deleted 1 row(s) from PHARMA_DW.PRODUCT_PRICE
2009-06-01 13:28:09,854 DEBUG Child table PRODUCT_FORECAST has 0 child records
2009-06-01 13:28:09,855 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:28:09,856 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.PRODUCT_FORECAST (TABLE)
2009-06-01 13:28:09,856 DEBUG Merging duplicate's child records on table PHARMA_DW.PRODUCT_FORECAST (TABLE)
2009-06-01 13:28:09,857 DEBUG Deleting duplicate's child records on table PHARMA_DW.PRODUCT_FORECAST (TABLE)
2009-06-01 13:28:09,905 DEBUG Child table PRODUCT_COST has 1 child records
2009-06-01 13:28:09,907 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:28:09,908 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.PRODUCT_COST (TABLE)
2009-06-01 13:28:09,913 DEBUG Finished merging on table PRODUCT
2009-06-01 13:28:09,916 INFO
Summary of modifications by table:
Table Update Delete Insert
PHARMA_DW.PRODUCT_PRICE 0 1 1
PHARMA_DW.PRODUCT_XREF 1 0 0

2009-06-01 13:28:09,922 ERROR Merge failed
java.lang.IllegalStateException: Merge Failed: Multiple records in table 'PRODUCT_COST' with the same primary key ([PRODUCT_ID: NUMBER(10), PERIOD_START_DATE: DATE(7)]) would be created on update.
at ca.sqlpower.matchmaker.MergeProcessor.mergeChildTables(MergeProcessor.java:519)
at ca.sqlpower.matchmaker.MergeProcessor.call(MergeProcessor.java:177)
at ca.sqlpower.matchmaker.MergeEngineImpl.call(MergeEngineImpl.java:167)
at ca.sqlpower.matchmaker.swingui.engine.EngineWorker.doStuff(EngineWorker.java:117)
at ca.sqlpower.swingui.SPSwingWorker.run(SPSwingWorker.java:99)
at java.lang.Thread.run(Unknown Source)
2009-06-01 13:28:09,933 ERROR Attempting rollback...
2009-06-01 13:28:09,957 INFO Rollback complete
2009-06-01 13:28:13,138 ERROR Error during engine run
java.lang.RuntimeException: java.lang.IllegalStateException: Merge Failed: Multiple records in table 'PRODUCT_COST' with the same primary key ([PRODUCT_ID: NUMBER(10), PERIOD_START_DATE: DATE(7)]) would be created on update.
at ca.sqlpower.matchmaker.MergeEngineImpl.call(MergeEngineImpl.java:193)
at ca.sqlpower.matchmaker.swingui.engine.EngineWorker.doStuff(EngineWorker.java:117)
at ca.sqlpower.swingui.SPSwingWorker.run(SPSwingWorker.java:99)
at java.lang.Thread.run(Unknown Source)
Caused by: java.lang.IllegalStateException: Merge Failed: Multiple records in table 'PRODUCT_COST' with the same primary key ([PRODUCT_ID: NUMBER(10), PERIOD_START_DATE: DATE(7)]) would be created on update.
at ca.sqlpower.matchmaker.MergeProcessor.mergeChildTables(MergeProcessor.java:519)
at ca.sqlpower.matchmaker.MergeProcessor.call(MergeProcessor.java:177)
at ca.sqlpower.matchmaker.MergeEngineImpl.call(MergeEngineImpl.java:167)
... 3 more
2009-06-01 13:29:15,028 INFO Checking Merge Engine Preconditions
2009-06-01 13:29:16,354 INFO Starting Merge Engine
2009-06-01 13:29:16,391 INFO Starting merge operation for project Product_Deduping
2009-06-01 13:29:16,395 INFO Loading match pool...
2009-06-01 13:29:16,898 DEBUG Found 2238 source table records in pool
2009-06-01 13:29:16,899 INFO Sorting matches...
2009-06-01 13:29:16,945 DEBUG Matches have been sorted; 1 merge operations to process
Planned processing order ([duplicate key] into [master key]):
[6] into [2067]
2009-06-01 13:29:16,951 DEBUG Merge rules for the source table's columns:
PRODUCT_ID Not applicable
LEGACY_PRODUCT_ID Augment nulls
PRODUCT_NAME Augment nulls
PRODUCT_DESCRIPTION_ENG Augment nulls
PRODUCT_DESCRIPTION_FR Augment nulls
PRODUCT_FORMULATION_ID Augment nulls
MANUFACTURER_NAME_CD Augment nulls
MANUFACTURER_NAME Augment nulls
THERAPEUTIC_CLASS_CD Augment nulls
null Augment nulls
SUB_THERAPEUTIC_CLASS_CD Augment nulls
null Augment nulls
PRODUCT_MARKET_NAME Augment nulls
STRENGTH_UNIT_OF_MEASURE_CD Augment nulls
STRENGTH_UNIT_OF_MEASURE Augment nulls
PRODUCT_STRENGTH_CD Augment nulls
PRODUCT_STRENGTH Augment nulls
PRODUCT_DOSAGE_FORM_CD Augment nulls
PRODUCT_DOSAGE_FORM Augment nulls
PRODUCT_PRESCRIPTION_CLASS_CD Augment nulls
PRODUCT_PRESCRIPTION_CLASS Augment nulls
STD_COST_PER_UNIT Augment nulls
SALEABLE_IND Augment nulls
PRODUCT_PACKAGE_TYPE_CD Augment nulls
PRODUCT_PKG_TYPE Augment nulls
PRODUCT_PKG_QTY Augment nulls
DIM_UNIT_OF_MEASURE_CD Augment nulls
DIM_UNIT_OF_MEASURE Augment nulls
PRODUCT_UNIT_WIDTH Augment nulls
PRODUCT_UNIT_HEIGHT Augment nulls
PRODUCT_UNIT_LENGTH Augment nulls
WEIGHT_UNIT_OF_MEASURE_CD Augment nulls
WEIGHT_UNIT_OF_MEASURE Augment nulls
PRODUCT_UNIT_WEIGHT Augment nulls
PROMOTED_PRODUCT_IND Augment nulls
PRODUCT_DIN Augment nulls
UPC_CD Augment nulls
BUDGET_GROUP_CD Augment nulls
BUDGET_GROUP Augment nulls
PRODUCT_CATEGORY_CD Augment nulls
PRODUCT_CATEGORY Augment nulls
TRADE_MANAGEMENT_GROUP_CD Augment nulls
TRADE_MANAGEMENT_GROUP Augment nulls
PRODUCT_FACT_A Augment nulls
PRODUCT_FACT_B Augment nulls
PRODUCT_FACT_C Augment nulls
PRODUCT_FACT_D Augment nulls
PRODUCT_FACT_E Augment nulls
SOURCE_ID Augment nulls
LAST_UPDATE_DATE Augment nulls
LAST_UPDATE_USER Augment nulls
FORECAST_QTY Augment nulls
FORECAST_DOLLARS Augment nulls
BUDGET_AMT Augment nulls
CURRENT_PRICE Augment nulls
null Augment nulls
2009-06-01 13:29:16,959 INFO ***** Merging record 1 of 1 *****
2009-06-01 13:29:16,965 DEBUG Duplicate record: [PRODUCT_ID=6]; master record: [PRODUCT_ID=2067]
2009-06-01 13:29:16,967 DEBUG Merging child records of PRODUCT ...
2009-06-01 13:29:16,968 DEBUG Duplicate: [6, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null]; Master: [2067, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null]
2009-06-01 13:29:16,972 DEBUG Child table PRODUCT_BUDGET has 0 child records
2009-06-01 13:29:16,973 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:29:16,974 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.PRODUCT_BUDGET (TABLE)
2009-06-01 13:29:16,975 DEBUG Merging duplicate's child records on table PHARMA_DW.PRODUCT_BUDGET (TABLE)
2009-06-01 13:29:16,975 DEBUG Deleting duplicate's child records on table PHARMA_DW.PRODUCT_BUDGET (TABLE)
2009-06-01 13:29:17,817 DEBUG Child table RETAIL_ACQUISITION has 0 child records
2009-06-01 13:29:17,819 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:29:17,820 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.RETAIL_ACQUISITION (TABLE)
2009-06-01 13:29:17,823 DEBUG Merging duplicate's child records on table PHARMA_DW.RETAIL_ACQUISITION (TABLE)
2009-06-01 13:29:17,824 DEBUG Deleting duplicate's child records on table PHARMA_DW.RETAIL_ACQUISITION (TABLE)
2009-06-01 13:29:17,919 DEBUG Child table ORDER_LINE has 0 child records
2009-06-01 13:29:17,921 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:29:17,922 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.ORDER_LINE (TABLE)
2009-06-01 13:29:17,924 DEBUG Merging duplicate's child records on table PHARMA_DW.ORDER_LINE (TABLE)
2009-06-01 13:29:17,925 DEBUG Deleting duplicate's child records on table PHARMA_DW.ORDER_LINE (TABLE)
2009-06-01 13:29:17,928 DEBUG Child table PRODUCT_XREF has 1 child records
2009-06-01 13:29:17,930 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:29:17,933 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.PRODUCT_XREF (TABLE)
2009-06-01 13:29:17,939 DEBUG generatePKWhereStatement returns:
WHERE LEGACY_SOURCE_ID='SAMPLE DATA' AND LEGACY_PRODUCT_ID='68443'
2009-06-01 13:29:17,940 DEBUG MergeProcessor.updateRow is executing the SQL statement:
UPDATE PHARMA_DW.PRODUCT_XREF SET
DW_PRODUCT_ID=2067,
LAST_UPDATE_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS'),
LAST_UPDATE_USER='PL'
WHERE LEGACY_SOURCE_ID='SAMPLE DATA' AND LEGACY_PRODUCT_ID='68443'
2009-06-01 13:29:17,943 DEBUG Modified 1 row(s) of PHARMA_DW.PRODUCT_XREF
2009-06-01 13:29:17,945 DEBUG Merging duplicate's child records on table PHARMA_DW.PRODUCT_XREF (TABLE)
2009-06-01 13:29:17,947 DEBUG Merging child records of PRODUCT_XREF ...
2009-06-01 13:29:17,948 DEBUG Duplicate: [SAMPLE DATA, 68443, 6, 2009-05-25, PL]; Master: [SAMPLE DATA, 68443, 2067, 2009-05-25, PL]
2009-06-01 13:29:17,949 DEBUG Finished merging on table PRODUCT_XREF
2009-06-01 13:29:17,953 DEBUG Deleting duplicate's child records on table PHARMA_DW.PRODUCT_XREF (TABLE)
2009-06-01 13:29:17,956 DEBUG Child table PRODUCT_PRICE has 1 child records
2009-06-01 13:29:17,957 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:29:17,959 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.PRODUCT_PRICE (TABLE)
2009-06-01 13:29:17,966 DEBUG Inserted 1 row(s) into PHARMA_DW.PRODUCT_PRICE
2009-06-01 13:29:17,968 DEBUG Merging duplicate's child records on table PHARMA_DW.PRODUCT_PRICE (TABLE)
2009-06-01 13:29:17,968 DEBUG Merging child records of PRODUCT_PRICE ...
2009-06-01 13:29:17,969 DEBUG Duplicate: [6, UNKNOWN, 2009-05-25, 0, null, SAMPLE DATA, 2009-05-25, PL]; Master: [2067, UNKNOWN, 2009-05-25, 0, null, SAMPLE DATA, 2009-05-25, PL]
2009-06-01 13:29:17,970 DEBUG Finished merging on table PRODUCT_PRICE
2009-06-01 13:29:17,971 DEBUG Deleting duplicate's child records on table PHARMA_DW.PRODUCT_PRICE (TABLE)
2009-06-01 13:29:17,986 DEBUG DELETE FROM PHARMA_DW.PRODUCT_PRICE
WHERE PRODUCT_ID=6 AND MARKET_SEGMENT_TYPE='UNKNOWN' AND PERIOD_START_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS')
2009-06-01 13:29:17,990 DEBUG Deleted 1 row(s) from PHARMA_DW.PRODUCT_PRICE
2009-06-01 13:29:17,994 DEBUG Child table PRODUCT_FORECAST has 0 child records
2009-06-01 13:29:17,995 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:29:17,996 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.PRODUCT_FORECAST (TABLE)
2009-06-01 13:29:17,997 DEBUG Merging duplicate's child records on table PHARMA_DW.PRODUCT_FORECAST (TABLE)
2009-06-01 13:29:17,998 DEBUG Deleting duplicate's child records on table PHARMA_DW.PRODUCT_FORECAST (TABLE)
2009-06-01 13:29:18,002 DEBUG Child table PRODUCT_COST has 1 child records
2009-06-01 13:29:18,003 DEBUG Merge Action is: Reassign child records, merge on conflict
2009-06-01 13:29:18,004 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.PRODUCT_COST (TABLE)
2009-06-01 13:29:18,009 DEBUG generatePKWhereStatement returns:
WHERE PRODUCT_ID=2067 AND PERIOD_START_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS')
2009-06-01 13:29:18,011 DEBUG MergeProcessor.findRowByWhereStatement: Executing SQL Statement: SELECT PRODUCT_ID, PERIOD_START_DATE, PERIOD_END_DT, PRODUCT_COST, SOURCE_ID, LAST_UPDATE_DATE, LAST_UPDATE_USER FROM PHARMA_DW.PRODUCT_COST
WHERE PRODUCT_ID=2067 AND PERIOD_START_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS')
2009-06-01 13:29:18,019 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:29:18,023 DEBUG cmr: ColumnMergeRule PRODUCT_ID, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Not applicable
2009-06-01 13:29:18,028 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:29:18,030 DEBUG cmr: ColumnMergeRule PERIOD_START_DATE, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Not applicable
2009-06-01 13:29:18,031 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:29:18,033 DEBUG cmr: ColumnMergeRule PERIOD_END_DT, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Augment nulls
2009-06-01 13:29:18,035 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:29:18,036 DEBUG cmr: ColumnMergeRule PRODUCT_COST, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Augment nulls
2009-06-01 13:29:18,039 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:29:18,040 DEBUG cmr: ColumnMergeRule SOURCE_ID, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Augment nulls
2009-06-01 13:29:18,042 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:29:18,044 DEBUG cmr: ColumnMergeRule LAST_UPDATE_DATE, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Augment nulls
2009-06-01 13:29:18,046 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:29:18,048 DEBUG cmr: ColumnMergeRule LAST_UPDATE_USER, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Augment nulls
2009-06-01 13:29:18,050 DEBUG generatePKWhereStatement returns:
WHERE PRODUCT_ID=2067 AND PERIOD_START_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS')
2009-06-01 13:29:18,054 DEBUG Modified 1 row(s) of PHARMA_DW.PRODUCT_COST
2009-06-01 13:29:18,055 DEBUG Merging duplicate's child records on table PHARMA_DW.PRODUCT_COST (TABLE)
2009-06-01 13:29:18,056 DEBUG Merging child records of PRODUCT_COST ...
2009-06-01 13:29:18,057 DEBUG Duplicate: [6, 2009-05-25, null, 0, SAMPLE DATA, 2009-05-25, PL]; Master: [2067, 2009-05-25, null, 0, SAMPLE DATA, 2009-05-25, PL]
2009-06-01 13:29:18,057 DEBUG Finished merging on table PRODUCT_COST
2009-06-01 13:29:18,059 DEBUG Deleting duplicate's child records on table PHARMA_DW.PRODUCT_COST (TABLE)
2009-06-01 13:29:18,060 DEBUG DELETE FROM PHARMA_DW.PRODUCT_COST
WHERE PRODUCT_ID=6 AND PERIOD_START_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS')
2009-06-01 13:29:18,063 DEBUG Deleted 1 row(s) from PHARMA_DW.PRODUCT_COST
2009-06-01 13:29:18,071 DEBUG Child table INCENTIVE_PROGRAM has 0 child records
2009-06-01 13:29:18,072 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:29:18,074 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.INCENTIVE_PROGRAM (TABLE)
2009-06-01 13:29:18,074 DEBUG Merging duplicate's child records on table PHARMA_DW.INCENTIVE_PROGRAM (TABLE)
2009-06-01 13:29:18,075 DEBUG Deleting duplicate's child records on table PHARMA_DW.INCENTIVE_PROGRAM (TABLE)
2009-06-01 13:29:18,076 DEBUG Finished merging on table PRODUCT
2009-06-01 13:29:18,076 DEBUG Updating source table columns according the merge actions...
2009-06-01 13:29:18,079 INFO
Summary of modifications by table:
Table Update Delete Insert
PHARMA_DW.PRODUCT_COST 1 1 0
PHARMA_DW.PRODUCT_PRICE 0 1 1
PHARMA_DW.PRODUCT_XREF 1 0 0

2009-06-01 13:29:18,081 ERROR Merge failed
java.lang.NullPointerException
at ca.sqlpower.matchmaker.TableMergeRules.getUniqueKeyColumns(TableMergeRules.java:479)
at ca.sqlpower.matchmaker.MergeProcessor.generateUKWhereStatement(MergeProcessor.java:999)
at ca.sqlpower.matchmaker.MergeProcessor.findRowByUniqueKey(MergeProcessor.java:897)
at ca.sqlpower.matchmaker.MergeProcessor.call(MergeProcessor.java:183)
at ca.sqlpower.matchmaker.MergeEngineImpl.call(MergeEngineImpl.java:167)
at ca.sqlpower.matchmaker.swingui.engine.EngineWorker.doStuff(EngineWorker.java:117)
at ca.sqlpower.swingui.SPSwingWorker.run(SPSwingWorker.java:99)
at java.lang.Thread.run(Unknown Source)
2009-06-01 13:29:18,086 ERROR Attempting rollback...
2009-06-01 13:29:18,146 INFO Rollback complete
2009-06-01 13:29:21,210 ERROR Error during engine run
java.lang.RuntimeException: java.lang.NullPointerException
at ca.sqlpower.matchmaker.MergeEngineImpl.call(MergeEngineImpl.java:193)
at ca.sqlpower.matchmaker.swingui.engine.EngineWorker.doStuff(EngineWorker.java:117)
at ca.sqlpower.swingui.SPSwingWorker.run(SPSwingWorker.java:99)
at java.lang.Thread.run(Unknown Source)
Caused by: java.lang.NullPointerException
at ca.sqlpower.matchmaker.TableMergeRules.getUniqueKeyColumns(TableMergeRules.java:479)
at ca.sqlpower.matchmaker.MergeProcessor.generateUKWhereStatement(MergeProcessor.java:999)
at ca.sqlpower.matchmaker.MergeProcessor.findRowByUniqueKey(MergeProcessor.java:897)
at ca.sqlpower.matchmaker.MergeProcessor.call(MergeProcessor.java:183)
at ca.sqlpower.matchmaker.MergeEngineImpl.call(MergeEngineImpl.java:167)
... 3 more
2009-06-01 13:32:13,543 INFO Checking Merge Engine Preconditions
2009-06-01 13:32:14,330 INFO Starting Merge Engine
2009-06-01 13:32:14,397 INFO Starting merge operation for project Product_Deduping
2009-06-01 13:32:14,398 INFO Loading match pool...
2009-06-01 13:32:14,802 DEBUG Found 2238 source table records in pool
2009-06-01 13:32:14,803 INFO Sorting matches...
2009-06-01 13:32:14,842 DEBUG Matches have been sorted; 1 merge operations to process
Planned processing order ([duplicate key] into [master key]):
[6] into [2067]
2009-06-01 13:32:14,850 DEBUG Merge rules for the source table's columns:
PRODUCT_ID Not applicable
LEGACY_PRODUCT_ID Augment nulls
PRODUCT_NAME Augment nulls
PRODUCT_DESCRIPTION_ENG Augment nulls
PRODUCT_DESCRIPTION_FR Augment nulls
PRODUCT_FORMULATION_ID Augment nulls
MANUFACTURER_NAME_CD Augment nulls
MANUFACTURER_NAME Augment nulls
THERAPEUTIC_CLASS_CD Augment nulls
null Augment nulls
SUB_THERAPEUTIC_CLASS_CD Augment nulls
null Augment nulls
PRODUCT_MARKET_NAME Augment nulls
STRENGTH_UNIT_OF_MEASURE_CD Augment nulls
STRENGTH_UNIT_OF_MEASURE Augment nulls
PRODUCT_STRENGTH_CD Augment nulls
PRODUCT_STRENGTH Augment nulls
PRODUCT_DOSAGE_FORM_CD Augment nulls
PRODUCT_DOSAGE_FORM Augment nulls
PRODUCT_PRESCRIPTION_CLASS_CD Augment nulls
PRODUCT_PRESCRIPTION_CLASS Augment nulls
STD_COST_PER_UNIT Augment nulls
SALEABLE_IND Augment nulls
PRODUCT_PACKAGE_TYPE_CD Augment nulls
PRODUCT_PKG_TYPE Augment nulls
PRODUCT_PKG_QTY Augment nulls
DIM_UNIT_OF_MEASURE_CD Augment nulls
DIM_UNIT_OF_MEASURE Augment nulls
PRODUCT_UNIT_WIDTH Augment nulls
PRODUCT_UNIT_HEIGHT Augment nulls
PRODUCT_UNIT_LENGTH Augment nulls
WEIGHT_UNIT_OF_MEASURE_CD Augment nulls
WEIGHT_UNIT_OF_MEASURE Augment nulls
PRODUCT_UNIT_WEIGHT Augment nulls
PROMOTED_PRODUCT_IND Augment nulls
PRODUCT_DIN Augment nulls
UPC_CD Augment nulls
BUDGET_GROUP_CD Augment nulls
BUDGET_GROUP Augment nulls
PRODUCT_CATEGORY_CD Augment nulls
PRODUCT_CATEGORY Augment nulls
TRADE_MANAGEMENT_GROUP_CD Augment nulls
TRADE_MANAGEMENT_GROUP Augment nulls
PRODUCT_FACT_A Augment nulls
PRODUCT_FACT_B Augment nulls
PRODUCT_FACT_C Augment nulls
PRODUCT_FACT_D Augment nulls
PRODUCT_FACT_E Augment nulls
SOURCE_ID Augment nulls
LAST_UPDATE_DATE Augment nulls
LAST_UPDATE_USER Augment nulls
FORECAST_QTY Augment nulls
FORECAST_DOLLARS Augment nulls
BUDGET_AMT Augment nulls
CURRENT_PRICE Augment nulls
null Augment nulls
2009-06-01 13:32:14,866 INFO ***** Merging record 1 of 1 *****
2009-06-01 13:32:14,870 DEBUG Duplicate record: [PRODUCT_ID=6]; master record: [PRODUCT_ID=2067]
2009-06-01 13:32:14,872 DEBUG Merging child records of PRODUCT ...
2009-06-01 13:32:14,873 DEBUG Duplicate: [6, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null]; Master: [2067, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null]
2009-06-01 13:32:14,882 DEBUG Child table PRODUCT_BUDGET has 0 child records
2009-06-01 13:32:14,883 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:32:14,884 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.PRODUCT_BUDGET (TABLE)
2009-06-01 13:32:14,885 DEBUG Merging duplicate's child records on table PHARMA_DW.PRODUCT_BUDGET (TABLE)
2009-06-01 13:32:14,886 DEBUG Deleting duplicate's child records on table PHARMA_DW.PRODUCT_BUDGET (TABLE)
2009-06-01 13:32:15,728 DEBUG Child table RETAIL_ACQUISITION has 0 child records
2009-06-01 13:32:15,730 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:32:15,731 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.RETAIL_ACQUISITION (TABLE)
2009-06-01 13:32:15,732 DEBUG Merging duplicate's child records on table PHARMA_DW.RETAIL_ACQUISITION (TABLE)
2009-06-01 13:32:15,734 DEBUG Deleting duplicate's child records on table PHARMA_DW.RETAIL_ACQUISITION (TABLE)
2009-06-01 13:32:15,825 DEBUG Child table ORDER_LINE has 0 child records
2009-06-01 13:32:15,825 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:32:15,827 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.ORDER_LINE (TABLE)
2009-06-01 13:32:15,827 DEBUG Merging duplicate's child records on table PHARMA_DW.ORDER_LINE (TABLE)
2009-06-01 13:32:15,828 DEBUG Deleting duplicate's child records on table PHARMA_DW.ORDER_LINE (TABLE)
2009-06-01 13:32:15,832 DEBUG Child table PRODUCT_XREF has 1 child records
2009-06-01 13:32:15,834 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:32:15,835 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.PRODUCT_XREF (TABLE)
2009-06-01 13:32:15,839 DEBUG generatePKWhereStatement returns:
WHERE LEGACY_SOURCE_ID='SAMPLE DATA' AND LEGACY_PRODUCT_ID='68443'
2009-06-01 13:32:15,840 DEBUG MergeProcessor.updateRow is executing the SQL statement:
UPDATE PHARMA_DW.PRODUCT_XREF SET
DW_PRODUCT_ID=2067,
LAST_UPDATE_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS'),
LAST_UPDATE_USER='PL'
WHERE LEGACY_SOURCE_ID='SAMPLE DATA' AND LEGACY_PRODUCT_ID='68443'
2009-06-01 13:32:15,842 DEBUG Modified 1 row(s) of PHARMA_DW.PRODUCT_XREF
2009-06-01 13:32:15,843 DEBUG Merging duplicate's child records on table PHARMA_DW.PRODUCT_XREF (TABLE)
2009-06-01 13:32:15,844 DEBUG Merging child records of PRODUCT_XREF ...
2009-06-01 13:32:15,845 DEBUG Duplicate: [SAMPLE DATA, 68443, 6, 2009-05-25, PL]; Master: [SAMPLE DATA, 68443, 2067, 2009-05-25, PL]
2009-06-01 13:32:15,846 DEBUG Finished merging on table PRODUCT_XREF
2009-06-01 13:32:15,847 DEBUG Deleting duplicate's child records on table PHARMA_DW.PRODUCT_XREF (TABLE)
2009-06-01 13:32:15,850 DEBUG Child table PRODUCT_PRICE has 1 child records
2009-06-01 13:32:15,852 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:32:15,853 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.PRODUCT_PRICE (TABLE)
2009-06-01 13:32:15,859 DEBUG Inserted 1 row(s) into PHARMA_DW.PRODUCT_PRICE
2009-06-01 13:32:15,861 DEBUG Merging duplicate's child records on table PHARMA_DW.PRODUCT_PRICE (TABLE)
2009-06-01 13:32:15,867 DEBUG Merging child records of PRODUCT_PRICE ...
2009-06-01 13:32:15,869 DEBUG Duplicate: [6, UNKNOWN, 2009-05-25, 0, null, SAMPLE DATA, 2009-05-25, PL]; Master: [2067, UNKNOWN, 2009-05-25, 0, null, SAMPLE DATA, 2009-05-25, PL]
2009-06-01 13:32:15,871 DEBUG Finished merging on table PRODUCT_PRICE
2009-06-01 13:32:15,872 DEBUG Deleting duplicate's child records on table PHARMA_DW.PRODUCT_PRICE (TABLE)
2009-06-01 13:32:15,874 DEBUG DELETE FROM PHARMA_DW.PRODUCT_PRICE
WHERE PRODUCT_ID=6 AND MARKET_SEGMENT_TYPE='UNKNOWN' AND PERIOD_START_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS')
2009-06-01 13:32:15,876 DEBUG Deleted 1 row(s) from PHARMA_DW.PRODUCT_PRICE
2009-06-01 13:32:15,880 DEBUG Child table PRODUCT_FORECAST has 0 child records
2009-06-01 13:32:15,887 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:32:15,889 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.PRODUCT_FORECAST (TABLE)
2009-06-01 13:32:15,891 DEBUG Merging duplicate's child records on table PHARMA_DW.PRODUCT_FORECAST (TABLE)
2009-06-01 13:32:15,892 DEBUG Deleting duplicate's child records on table PHARMA_DW.PRODUCT_FORECAST (TABLE)
2009-06-01 13:32:15,895 DEBUG Child table PRODUCT_COST has 1 child records
2009-06-01 13:32:15,896 DEBUG Merge Action is: Reassign child records, merge on conflict
2009-06-01 13:32:15,897 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.PRODUCT_COST (TABLE)
2009-06-01 13:32:15,901 DEBUG generatePKWhereStatement returns:
WHERE PRODUCT_ID=2067 AND PERIOD_START_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS')
2009-06-01 13:32:15,902 DEBUG MergeProcessor.findRowByWhereStatement: Executing SQL Statement: SELECT PRODUCT_ID, PERIOD_START_DATE, PERIOD_END_DT, PRODUCT_COST, SOURCE_ID, LAST_UPDATE_DATE, LAST_UPDATE_USER FROM PHARMA_DW.PRODUCT_COST
WHERE PRODUCT_ID=2067 AND PERIOD_START_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS')
2009-06-01 13:32:15,907 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:32:15,908 DEBUG cmr: ColumnMergeRule PRODUCT_ID, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Not applicable
2009-06-01 13:32:15,909 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:32:15,910 DEBUG cmr: ColumnMergeRule PERIOD_START_DATE, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Not applicable
2009-06-01 13:32:15,912 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:32:15,914 DEBUG cmr: ColumnMergeRule PERIOD_END_DT, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Augment nulls
2009-06-01 13:32:15,914 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:32:15,915 DEBUG cmr: ColumnMergeRule PRODUCT_COST, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Augment nulls
2009-06-01 13:32:15,916 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:32:15,917 DEBUG cmr: ColumnMergeRule SOURCE_ID, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Augment nulls
2009-06-01 13:32:15,918 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:32:15,919 DEBUG cmr: ColumnMergeRule LAST_UPDATE_DATE, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Augment nulls
2009-06-01 13:32:15,920 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:32:15,921 DEBUG cmr: ColumnMergeRule LAST_UPDATE_USER, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Augment nulls
2009-06-01 13:32:15,923 DEBUG generatePKWhereStatement returns:
WHERE PRODUCT_ID=2067 AND PERIOD_START_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS')
2009-06-01 13:32:15,925 DEBUG Modified 1 row(s) of PHARMA_DW.PRODUCT_COST
2009-06-01 13:32:15,926 DEBUG Merging duplicate's child records on table PHARMA_DW.PRODUCT_COST (TABLE)
2009-06-01 13:32:15,927 DEBUG Merging child records of PRODUCT_COST ...
2009-06-01 13:32:15,928 DEBUG Duplicate: [6, 2009-05-25, null, 0, SAMPLE DATA, 2009-05-25, PL]; Master: [2067, 2009-05-25, null, 0, SAMPLE DATA, 2009-05-25, PL]
2009-06-01 13:32:15,929 DEBUG Finished merging on table PRODUCT_COST
2009-06-01 13:32:15,931 DEBUG Deleting duplicate's child records on table PHARMA_DW.PRODUCT_COST (TABLE)
2009-06-01 13:32:15,932 DEBUG DELETE FROM PHARMA_DW.PRODUCT_COST
WHERE PRODUCT_ID=6 AND PERIOD_START_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS')
2009-06-01 13:32:15,934 DEBUG Deleted 1 row(s) from PHARMA_DW.PRODUCT_COST
2009-06-01 13:32:15,938 DEBUG Child table INCENTIVE_PROGRAM has 0 child records
2009-06-01 13:32:15,938 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:32:15,939 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.INCENTIVE_PROGRAM (TABLE)
2009-06-01 13:32:15,940 DEBUG Merging duplicate's child records on table PHARMA_DW.INCENTIVE_PROGRAM (TABLE)
2009-06-01 13:32:15,941 DEBUG Deleting duplicate's child records on table PHARMA_DW.INCENTIVE_PROGRAM (TABLE)
2009-06-01 13:32:15,943 DEBUG Finished merging on table PRODUCT
2009-06-01 13:32:15,944 DEBUG Updating source table columns according the merge actions...
2009-06-01 13:32:15,946 INFO
Summary of modifications by table:
Table Update Delete Insert
PHARMA_DW.PRODUCT_COST 1 1 0
PHARMA_DW.PRODUCT_PRICE 0 1 1
PHARMA_DW.PRODUCT_XREF 1 0 0

2009-06-01 13:32:15,948 ERROR Merge failed
java.lang.NullPointerException
at ca.sqlpower.matchmaker.TableMergeRules.getUniqueKeyColumns(TableMergeRules.java:479)
at ca.sqlpower.matchmaker.MergeProcessor.generateUKWhereStatement(MergeProcessor.java:999)
at ca.sqlpower.matchmaker.MergeProcessor.findRowByUniqueKey(MergeProcessor.java:897)
at ca.sqlpower.matchmaker.MergeProcessor.call(MergeProcessor.java:183)
at ca.sqlpower.matchmaker.MergeEngineImpl.call(MergeEngineImpl.java:167)
at ca.sqlpower.matchmaker.swingui.engine.EngineWorker.doStuff(EngineWorker.java:117)
at ca.sqlpower.swingui.SPSwingWorker.run(SPSwingWorker.java:99)
at java.lang.Thread.run(Unknown Source)
2009-06-01 13:32:15,956 ERROR Attempting rollback...
2009-06-01 13:32:15,973 INFO Rollback complete
2009-06-01 13:32:19,047 ERROR Error during engine run
java.lang.RuntimeException: java.lang.NullPointerException
at ca.sqlpower.matchmaker.MergeEngineImpl.call(MergeEngineImpl.java:193)
at ca.sqlpower.matchmaker.swingui.engine.EngineWorker.doStuff(EngineWorker.java:117)
at ca.sqlpower.swingui.SPSwingWorker.run(SPSwingWorker.java:99)
at java.lang.Thread.run(Unknown Source)
Caused by: java.lang.NullPointerException
at ca.sqlpower.matchmaker.TableMergeRules.getUniqueKeyColumns(TableMergeRules.java:479)
at ca.sqlpower.matchmaker.MergeProcessor.generateUKWhereStatement(MergeProcessor.java:999)
at ca.sqlpower.matchmaker.MergeProcessor.findRowByUniqueKey(MergeProcessor.java:897)
at ca.sqlpower.matchmaker.MergeProcessor.call(MergeProcessor.java:183)
at ca.sqlpower.matchmaker.MergeEngineImpl.call(MergeEngineImpl.java:167)
... 3 more
2009-06-01 13:37:15,799 INFO Checking Merge Engine Preconditions
2009-06-01 13:37:16,613 INFO Starting Merge Engine
2009-06-01 13:37:16,647 INFO Starting merge operation for project Product_Deduping
2009-06-01 13:37:16,648 INFO Loading match pool...
2009-06-01 13:37:17,040 DEBUG Found 2238 source table records in pool
2009-06-01 13:37:17,041 INFO Sorting matches...
2009-06-01 13:37:17,070 DEBUG Matches have been sorted; 1 merge operations to process
Planned processing order ([duplicate key] into [master key]):
[6] into [2067]
2009-06-01 13:37:17,074 DEBUG Merge rules for the source table's columns:
PRODUCT_ID Not applicable
LEGACY_PRODUCT_ID Augment nulls
PRODUCT_NAME Augment nulls
PRODUCT_DESCRIPTION_ENG Augment nulls
PRODUCT_DESCRIPTION_FR Augment nulls
PRODUCT_FORMULATION_ID Augment nulls
MANUFACTURER_NAME_CD Augment nulls
MANUFACTURER_NAME Augment nulls
THERAPEUTIC_CLASS_CD Augment nulls
null Augment nulls
SUB_THERAPEUTIC_CLASS_CD Augment nulls
null Augment nulls
PRODUCT_MARKET_NAME Augment nulls
STRENGTH_UNIT_OF_MEASURE_CD Augment nulls
STRENGTH_UNIT_OF_MEASURE Augment nulls
PRODUCT_STRENGTH_CD Augment nulls
PRODUCT_STRENGTH Augment nulls
PRODUCT_DOSAGE_FORM_CD Augment nulls
PRODUCT_DOSAGE_FORM Augment nulls
PRODUCT_PRESCRIPTION_CLASS_CD Augment nulls
PRODUCT_PRESCRIPTION_CLASS Augment nulls
STD_COST_PER_UNIT Augment nulls
SALEABLE_IND Augment nulls
PRODUCT_PACKAGE_TYPE_CD Augment nulls
PRODUCT_PKG_TYPE Augment nulls
PRODUCT_PKG_QTY Augment nulls
DIM_UNIT_OF_MEASURE_CD Augment nulls
DIM_UNIT_OF_MEASURE Augment nulls
PRODUCT_UNIT_WIDTH Augment nulls
PRODUCT_UNIT_HEIGHT Augment nulls
PRODUCT_UNIT_LENGTH Augment nulls
WEIGHT_UNIT_OF_MEASURE_CD Augment nulls
WEIGHT_UNIT_OF_MEASURE Augment nulls
PRODUCT_UNIT_WEIGHT Augment nulls
PROMOTED_PRODUCT_IND Augment nulls
PRODUCT_DIN Augment nulls
UPC_CD Augment nulls
BUDGET_GROUP_CD Augment nulls
BUDGET_GROUP Augment nulls
PRODUCT_CATEGORY_CD Augment nulls
PRODUCT_CATEGORY Augment nulls
TRADE_MANAGEMENT_GROUP_CD Augment nulls
TRADE_MANAGEMENT_GROUP Augment nulls
PRODUCT_FACT_A Augment nulls
PRODUCT_FACT_B Augment nulls
PRODUCT_FACT_C Augment nulls
PRODUCT_FACT_D Augment nulls
PRODUCT_FACT_E Augment nulls
SOURCE_ID Augment nulls
LAST_UPDATE_DATE Augment nulls
LAST_UPDATE_USER Augment nulls
FORECAST_QTY Augment nulls
FORECAST_DOLLARS Augment nulls
BUDGET_AMT Augment nulls
CURRENT_PRICE Augment nulls
null Augment nulls
2009-06-01 13:37:17,079 INFO ***** Merging record 1 of 1 *****
2009-06-01 13:37:17,084 DEBUG Duplicate record: [PRODUCT_ID=6]; master record: [PRODUCT_ID=2067]
2009-06-01 13:37:17,085 DEBUG Merging child records of PRODUCT ...
2009-06-01 13:37:17,085 DEBUG Duplicate: [6, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null]; Master: [2067, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null]
2009-06-01 13:37:17,101 DEBUG Child table PRODUCT_BUDGET has 0 child records
2009-06-01 13:37:17,102 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:37:17,102 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.PRODUCT_BUDGET (TABLE)
2009-06-01 13:37:17,103 DEBUG Merging duplicate's child records on table PHARMA_DW.PRODUCT_BUDGET (TABLE)
2009-06-01 13:37:17,104 DEBUG Deleting duplicate's child records on table PHARMA_DW.PRODUCT_BUDGET (TABLE)
2009-06-01 13:37:17,960 DEBUG Child table RETAIL_ACQUISITION has 0 child records
2009-06-01 13:37:17,962 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:37:17,962 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.RETAIL_ACQUISITION (TABLE)
2009-06-01 13:37:17,965 DEBUG Merging duplicate's child records on table PHARMA_DW.RETAIL_ACQUISITION (TABLE)
2009-06-01 13:37:17,966 DEBUG Deleting duplicate's child records on table PHARMA_DW.RETAIL_ACQUISITION (TABLE)
2009-06-01 13:37:18,063 DEBUG Child table ORDER_LINE has 0 child records
2009-06-01 13:37:18,068 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:37:18,071 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.ORDER_LINE (TABLE)
2009-06-01 13:37:18,074 DEBUG Merging duplicate's child records on table PHARMA_DW.ORDER_LINE (TABLE)
2009-06-01 13:37:18,075 DEBUG Deleting duplicate's child records on table PHARMA_DW.ORDER_LINE (TABLE)
2009-06-01 13:37:18,080 DEBUG Child table PRODUCT_XREF has 1 child records
2009-06-01 13:37:18,083 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:37:18,086 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.PRODUCT_XREF (TABLE)
2009-06-01 13:37:18,101 DEBUG generatePKWhereStatement returns:
WHERE LEGACY_SOURCE_ID='SAMPLE DATA' AND LEGACY_PRODUCT_ID='68443'
2009-06-01 13:37:18,103 DEBUG MergeProcessor.updateRow is executing the SQL statement:
UPDATE PHARMA_DW.PRODUCT_XREF SET
DW_PRODUCT_ID=2067,
LAST_UPDATE_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS'),
LAST_UPDATE_USER='PL'
WHERE LEGACY_SOURCE_ID='SAMPLE DATA' AND LEGACY_PRODUCT_ID='68443'
2009-06-01 13:37:18,105 DEBUG Modified 1 row(s) of PHARMA_DW.PRODUCT_XREF
2009-06-01 13:37:18,109 DEBUG Merging duplicate's child records on table PHARMA_DW.PRODUCT_XREF (TABLE)
2009-06-01 13:37:18,120 DEBUG Merging child records of PRODUCT_XREF ...
2009-06-01 13:37:18,123 DEBUG Duplicate: [SAMPLE DATA, 68443, 6, 2009-05-25, PL]; Master: [SAMPLE DATA, 68443, 2067, 2009-05-25, PL]
2009-06-01 13:37:18,125 DEBUG Finished merging on table PRODUCT_XREF
2009-06-01 13:37:18,127 DEBUG Deleting duplicate's child records on table PHARMA_DW.PRODUCT_XREF (TABLE)
2009-06-01 13:37:18,134 DEBUG Child table PRODUCT_PRICE has 1 child records
2009-06-01 13:37:18,136 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:37:18,138 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.PRODUCT_PRICE (TABLE)
2009-06-01 13:37:18,148 DEBUG Inserted 1 row(s) into PHARMA_DW.PRODUCT_PRICE
2009-06-01 13:37:18,149 DEBUG Merging duplicate's child records on table PHARMA_DW.PRODUCT_PRICE (TABLE)
2009-06-01 13:37:18,151 DEBUG Merging child records of PRODUCT_PRICE ...
2009-06-01 13:37:18,152 DEBUG Duplicate: [6, UNKNOWN, 2009-05-25, 0, null, SAMPLE DATA, 2009-05-25, PL]; Master: [2067, UNKNOWN, 2009-05-25, 0, null, SAMPLE DATA, 2009-05-25, PL]
2009-06-01 13:37:18,154 DEBUG Finished merging on table PRODUCT_PRICE
2009-06-01 13:37:18,155 DEBUG Deleting duplicate's child records on table PHARMA_DW.PRODUCT_PRICE (TABLE)
2009-06-01 13:37:18,159 DEBUG DELETE FROM PHARMA_DW.PRODUCT_PRICE
WHERE PRODUCT_ID=6 AND MARKET_SEGMENT_TYPE='UNKNOWN' AND PERIOD_START_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS')
2009-06-01 13:37:18,162 DEBUG Deleted 1 row(s) from PHARMA_DW.PRODUCT_PRICE
2009-06-01 13:37:18,166 DEBUG Child table PRODUCT_FORECAST has 0 child records
2009-06-01 13:37:18,169 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:37:18,171 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.PRODUCT_FORECAST (TABLE)
2009-06-01 13:37:18,172 DEBUG Merging duplicate's child records on table PHARMA_DW.PRODUCT_FORECAST (TABLE)
2009-06-01 13:37:18,176 DEBUG Deleting duplicate's child records on table PHARMA_DW.PRODUCT_FORECAST (TABLE)
2009-06-01 13:37:18,180 DEBUG Child table PRODUCT_COST has 1 child records
2009-06-01 13:37:18,183 DEBUG Merge Action is: Reassign child records, merge on conflict
2009-06-01 13:37:18,185 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.PRODUCT_COST (TABLE)
2009-06-01 13:37:18,190 DEBUG generatePKWhereStatement returns:
WHERE PRODUCT_ID=2067 AND PERIOD_START_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS')
2009-06-01 13:37:18,192 DEBUG MergeProcessor.findRowByWhereStatement: Executing SQL Statement: SELECT PRODUCT_ID, PERIOD_START_DATE, PERIOD_END_DT, PRODUCT_COST, SOURCE_ID, LAST_UPDATE_DATE, LAST_UPDATE_USER FROM PHARMA_DW.PRODUCT_COST
WHERE PRODUCT_ID=2067 AND PERIOD_START_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS')
2009-06-01 13:37:18,198 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:37:18,199 DEBUG cmr: ColumnMergeRule PRODUCT_ID, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Not applicable
2009-06-01 13:37:18,202 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:37:18,204 DEBUG cmr: ColumnMergeRule PERIOD_START_DATE, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Not applicable
2009-06-01 13:37:18,205 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:37:18,207 DEBUG cmr: ColumnMergeRule PERIOD_END_DT, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Augment nulls
2009-06-01 13:37:18,210 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:37:18,211 DEBUG cmr: ColumnMergeRule PRODUCT_COST, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Augment nulls
2009-06-01 13:37:18,212 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:37:18,214 DEBUG cmr: ColumnMergeRule SOURCE_ID, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Augment nulls
2009-06-01 13:37:18,216 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:37:18,218 DEBUG cmr: ColumnMergeRule LAST_UPDATE_DATE, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Augment nulls
2009-06-01 13:37:18,220 DEBUG dupRowValues: [PRODUCT_ID=6, PERIOD_START_DATE=2009-05-25, PRODUCT_COST=0, SOURCE_ID=SAMPLE DATA, LAST_UPDATE_DATE=2009-05-25, LAST_UPDATE_USER=PL]
2009-06-01 13:37:18,227 DEBUG cmr: ColumnMergeRule LAST_UPDATE_USER, Parent: Merge Strategy->'PHARMA_DW.PRODUCT_COST' Parent->'Folder "Merge Rules"' , ActionType: Augment nulls
2009-06-01 13:37:18,230 DEBUG generatePKWhereStatement returns:
WHERE PRODUCT_ID=2067 AND PERIOD_START_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS')
2009-06-01 13:37:18,234 DEBUG Modified 1 row(s) of PHARMA_DW.PRODUCT_COST
2009-06-01 13:37:18,235 DEBUG Merging duplicate's child records on table PHARMA_DW.PRODUCT_COST (TABLE)
2009-06-01 13:37:18,237 DEBUG Merging child records of PRODUCT_COST ...
2009-06-01 13:37:18,238 DEBUG Duplicate: [6, 2009-05-25, null, 0, SAMPLE DATA, 2009-05-25, PL]; Master: [2067, 2009-05-25, null, 0, SAMPLE DATA, 2009-05-25, PL]
2009-06-01 13:37:18,240 DEBUG Finished merging on table PRODUCT_COST
2009-06-01 13:37:18,241 DEBUG Deleting duplicate's child records on table PHARMA_DW.PRODUCT_COST (TABLE)
2009-06-01 13:37:18,243 DEBUG DELETE FROM PHARMA_DW.PRODUCT_COST
WHERE PRODUCT_ID=6 AND PERIOD_START_DATE=TO_DATE('2009-05-25 00:00:00','YYYY-MM-DD HH24:MI:SS')
2009-06-01 13:37:18,246 DEBUG Deleted 1 row(s) from PHARMA_DW.PRODUCT_COST
2009-06-01 13:37:18,250 DEBUG Child table INCENTIVE_PROGRAM has 0 child records
2009-06-01 13:37:18,251 DEBUG Merge Action is: Reassign child records, fail on conflict
2009-06-01 13:37:18,253 DEBUG Creating a copy of the duplicate record's children on table PHARMA_DW.INCENTIVE_PROGRAM (TABLE)
2009-06-01 13:37:18,254 DEBUG Merging duplicate's child records on table PHARMA_DW.INCENTIVE_PROGRAM (TABLE)
2009-06-01 13:37:18,256 DEBUG Deleting duplicate's child records on table PHARMA_DW.INCENTIVE_PROGRAM (TABLE)
2009-06-01 13:37:18,257 DEBUG Finished merging on table PRODUCT
2009-06-01 13:37:18,259 DEBUG Updating source table columns according the merge actions...
2009-06-01 13:37:18,261 INFO
Summary of modifications by table:
Table Update Delete Insert
PHARMA_DW.PRODUCT_COST 1 1 0
PHARMA_DW.PRODUCT_PRICE 0 1 1
PHARMA_DW.PRODUCT_XREF 1 0 0

2009-06-01 13:37:18,266 ERROR Merge failed
java.lang.NullPointerException
at ca.sqlpower.matchmaker.TableMergeRules.getUniqueKeyColumns(TableMergeRules.java:479)
at ca.sqlpower.matchmaker.MergeProcessor.generateUKWhereStatement(MergeProcessor.java:999)
at ca.sqlpower.matchmaker.MergeProcessor.findRowByUniqueKey(MergeProcessor.java:897)
at ca.sqlpower.matchmaker.MergeProcessor.call(MergeProcessor.java:183)
at ca.sqlpower.matchmaker.MergeEngineImpl.call(MergeEngineImpl.java:167)
at ca.sqlpower.matchmaker.swingui.engine.EngineWorker.doStuff(EngineWorker.java:117)
at ca.sqlpower.swingui.SPSwingWorker.run(SPSwingWorker.java:99)
at java.lang.Thread.run(Unknown Source)
2009-06-01 13:37:18,272 ERROR Attempting rollback...
2009-06-01 13:37:18,275 INFO Rollback complete
2009-06-01 13:37:21,356 ERROR Error during engine run
java.lang.RuntimeException: java.lang.NullPointerException
at ca.sqlpower.matchmaker.MergeEngineImpl.call(MergeEngineImpl.java:193)
at ca.sqlpower.matchmaker.swingui.engine.EngineWorker.doStuff(EngineWorker.java:117)
at ca.sqlpower.swingui.SPSwingWorker.run(SPSwingWorker.java:99)
at java.lang.Thread.run(Unknown Source)
Caused by: java.lang.NullPointerException
at ca.sqlpower.matchmaker.TableMergeRules.getUniqueKeyColumns(TableMergeRules.java:479)
at ca.sqlpower.matchmaker.MergeProcessor.generateUKWhereStatement(MergeProcessor.java:999)
at ca.sqlpower.matchmaker.MergeProcessor.findRowByUniqueKey(MergeProcessor.java:897)
at ca.sqlpower.matchmaker.MergeProcessor.call(MergeProcessor.java:183)
at ca.sqlpower.matchmaker.MergeEngineImpl.call(MergeEngineImpl.java:167)
... 3 more

Expected Result: The 2 records would be merged.

I would not be surprised if this error is directly related to the previous error that occurred when deriving the merge rules. It's probable that the error resulted in the merge rules being in a bad state.