duplicate key problem after update on 2012-10-06

[blacklevel]

Hi,

my test setup was on database migration version "922" along with the matching application release which was current when migration 922 was checked in. I updated via 

./update.sh http://jenkins.idempiere.com/job/iDempiere/ws/buckminster.output/org.adempiere.server_1.0.0-eclipse.feature/site.p2/

After that I failed to notice that there was a new migration "924" was introduced (what happened t "923"?). So I started the idempiere server while still being on "922" and got errors:

08:56:50.287 WebEnv.initWeb: Servlet Init Parameter: AdempiereMonitor [11]

08:56:50.288 AdempiereMonitor.init:  [11]

08:56:50.675===========> DB.executeUpdate: INSERT INTO AD_Session (Remote_Addr,Remote_Host,AD_Session_ID,Processed,AD_Role_ID,LoginDate,Description,AD_Session_UU,UpdatedBy,CreatedBy,Created,Updated,AD_Client_ID,IsActive,AD_Org_ID) VALUES (?,?,?,?,?,trunc(cast(? as TIMESTAMP)),?,?,?,?,?,?,?,?,?) [POSaveAD_Session_67b4109b-44c2-4902-a705-d809960d4e20] [11]

org.postgresql.util.PSQLException: ERROR: duplicate key value violates unique constraint "ad_session_pkey"

  Detail: Key (ad_session_id)=(1000032) already exists.; State=23505; ErrorCode=0

at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2102)

at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1835)

at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:257)

at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:500)

at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:388)

at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:334)

at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:105)

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:616)

at org.compiere.db.StatementProxy.invoke(StatementProxy.java:125)

at $Proxy0.executeUpdate(Unknown Source)

at org.compiere.util.DB.executeUpdate(DB.java:1027)

at org.compiere.util.DB.executeUpdate(DB.java:992)

at org.compiere.model.PO.doInsert(PO.java:2897)

at org.compiere.model.PO.saveNew(PO.java:2701)

at org.compiere.model.PO.save(PO.java:2070)

at org.compiere.model.PO.saveEx(PO.java:2154)

at org.compiere.model.MSession.get(MSession.java:75)

at org.compiere.server.AdempiereServerMgr.startEnvironment(AdempiereServerMgr.java:94)

at org.compiere.server.AdempiereServerMgr.<init>(AdempiereServerMgr.java:73)

at org.compiere.server.AdempiereServerMgr.get(AdempiereServerMgr.java:55)

at org.compiere.web.AdempiereMonitor.init(AdempiereMonitor.java:1025)

(...)

08:56:50.982===========> DB.executeUpdate: INSERT INTO AD_Issue (JavaInfo,ReleaseTag,Processed,OperatingSystemInfo,DatabaseInfo,StatisticsInfo,Local_Host,AD_Issue_UU,Version,DBAddress,IssueSummary,Record_ID,AD_Issue_ID,ProfileInfo,SystemStatus,ErrorTrace,ReleaseNo,UserName,SourceClassName,SourceMethodName,LoggerName,StackTrace,Processing,Created,IsActive,CreatedBy,Updated,UpdatedBy,AD_Client_ID,AD_Org_ID,Name) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?) [POSaveAD_Issue_7f540850-6178-4426-a511-832840728c80] [11]

org.postgresql.util.PSQLException: ERROR: duplicate key value violates unique constraint "ad_issue_pkey"

  Detail: Key (ad_issue_id)=(1000089) already exists.; State=23505; ErrorCode=0

at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2102)

at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1835)

at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:257)

at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:500)

at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:388)

at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:334)

at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:105)

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:616)

at org.compiere.db.StatementProxy.invoke(StatementProxy.java:125)

at $Proxy0.executeUpdate(Unknown Source)

at org.compiere.util.DB.executeUpdate(DB.java:1027)

at org.compiere.util.DB.executeUpdate(DB.java:992)

at org.compiere.model.PO.doInsert(PO.java:2897)

at org.compiere.model.PO.saveNew(PO.java:2701)

at org.compiere.model.PO.save(PO.java:2070)

at org.compiere.model.PO.saveEx(PO.java:2154)

at org.compiere.model.MIssue.create(MIssue.java:76)

at org.compiere.util.CLogErrorBuffer.publish(CLogErrorBuffer.java:199)

08:56:50.986===========> DB.saveError: DBExecuteError - ERROR: duplicate key value violates unique constraint "ad_issue_pkey"

  Detail: Key (ad_issue_id)=(1000089) already exists. [11]

08:56:50.986-----------> MIssue.doInsert: [POSaveAD_Issue_7f540850-6178-4426-a511-832840728c80]Not inserted - AD_Issue [11]

08:56:50.675===========> DB.executeUpdate: INSERT INTO AD_Session (Remote_Addr,Remote_Host,AD_Session_ID,Processed,AD_Role_ID,LoginDate,Description,AD_Session_UU,UpdatedBy,CreatedBy,Created,Updated,AD_Client_ID,IsActive,AD_Org_ID) VALUES (?,?,?,?,?,trunc(cast(? as TIMESTAMP)),?,?,?,?,?,?,?,?,?) [POSaveAD_Session_67b4109b-44c2-4902-a705-d809960d4e20] [11]

org.postgresql.util.PSQLException: ERROR: duplicate key value violates unique constraint "ad_session_pkey"

  Detail: Key (ad_session_id)=(1000032) already exists.; State=23505; ErrorCode=0

at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2102)

at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1835)

at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:257)

at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:500)

at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:388)

at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:334)

at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:105)

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:616)

at org.compiere.db.StatementProxy.invoke(StatementProxy.java:125)

at $Proxy0.executeUpdate(Unknown Source)

at org.compiere.util.DB.executeUpdate(DB.java:1027)

at org.compiere.util.DB.executeUpdate(DB.java:992)

at org.compiere.model.PO.doInsert(PO.java:2897)

at org.compiere.model.PO.saveNew(PO.java:2701)

at org.compiere.model.PO.save(PO.java:2070)

at org.compiere.model.PO.saveEx(PO.java:2154)

at org.compiere.model.MSession.get(MSession.java:75)

at org.compiere.server.AdempiereServerMgr.startEnvironment(AdempiereServerMgr.java:94)

at org.compiere.server.AdempiereServerMgr.<init>(AdempiereServerMgr.java:73)

at org.compiere.server.AdempiereServerMgr.get(AdempiereServerMgr.java:55)

at org.compiere.web.AdempiereMonitor.init(AdempiereMonitor.java:1025)

After investigating I found the 924 migration and applied it. But the duplicate key problem remains. I did try to clean the AD_Session table by deleting the conflicting record. That worked temporarily. idempiere inserted the session with "ad_session_id=1000032" and the problem returned.

After some more investigating I found that older migrations (which I had previously applied) were altered during the commit. (As far as i understand the concept of database migrations this should not have been done this way.) So I tried to reapply these older modified migrations as a whole, which maybe was a bad idea.

This did not work. 

Then I manually updated the "ad_sequence" table where name='AD_Session' with currrentnext=1000033.

That also did not help. The error remained, only that it said that now 1000033 is the duplicate key. Somehow, it seems, the key maintenance mechanism got messed up. 

Is there a way to fix this other than to start from scratch with a new database seed and reapplying all migrations from the beginning?

Thanks

Michael

[Dirk Niemeyer]

Hi Michael,

login using SystemAdministrator as role and run
Menu > System Admin > General Rules > Sequence Check

That process may solve your problem.

Regards

Dirk Niemeyer

[Anton Sokolov]

I have same issue. Sequence Check found many errors but doesn't help.

понедельник, 8 октября 2012 г., 15:45:07 UTC+4 пользователь Dirk Niemeyer написал:

[Carlos Antonio Ruiz Gomez]

My fault, working on it - thanks for reporting.

Regards,

Carlos Ruiz

[blacklevel]

Thanks!

Best Regards

Michael

[Carlos Antonio Ruiz Gomez]

Hi, must be solved now with latest commits.

Please run again the sequence check script/process after pulling/updating.

Regards,

Carlos Ruiz

[blacklevel]

Hi Carlos,

it looks very good here. After updating idempiere and restarting the application server I again got a duplicate key error message for ad_session_pkey but I could successfully bring up the webinterface. That did not work before.

The sequence check returned this information:

** Sequence Check

AD_Column Sys 200580 -> 200581

AD_Element Sys 200160 -> 200171

AD_Field Sys 200594 -> 200595

AD_UserMail ID 1000086 -> 1000087

AD_WorkflowProcessorLog ID 1000014 -> 1000015

C_AcctProcessorLog ID 1000140 -> 1000141

R_RequestProcessorLog ID 1000088 -> 1000089

One thing worth mentioning: the idempiere server log only showed errors during the application server startup. Since then no more errors.

Thanks and best regards

Michael