Hide Forgot
This exception appears at various times in various environments for unknown reasons and fills up the log files and prevents refreshes from finishing for this owner. -04:00] [app:] ERROR org.hibernate.jdbc.AbstractBatcher - Exception executing batch: .556049-04:00] [app:java.lang.RuntimeException] java.sql.BatchUpdateException: Duplicate entry '3013983-master' for key 'subscriptionId' .556056-04:00] [app:] at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:2443) .556056-04:00] [app:] at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:70) .556059-04:00] [app:] at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:268) .556059-04:00] [app:] at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:114) .556061-04:00] [app:] at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:109) .556061-04:00] [app:] at org.hibernate.jdbc.AbstractBatcher.prepareBatchStatement(AbstractBatcher.java:244) .556241-04:00] [app:] at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2242) .556241-04:00] [app:] at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2678) .556265-04:00] [app:] at org.hibernate.action.EntityInsertAction.execute(EntityInsertAction.java:79) .556265-04:00] [app:] at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:278) .556268-04:00] [app:] at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:262) .556268-04:00] [app:] at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:166) .556271-04:00] [app:] at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321) .556271-04:00] [app:] at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:50) .556274-04:00] [app:] at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1030) .556274-04:00] [app:] at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:367) .556277-04:00] [app:] at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:137) .556277-04:00] [app:] at org.hibernate.ejb.TransactionImpl.commit(TransactionImpl.java:54) .556279-04:00] [app:] at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(JpaLocalTxnInterceptor.java:71) .556279-04:00] [app:] at com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:72) .556282-04:00] [app:] at com.google.inject.internal.InterceptorStackCallback.intercept(InterceptorStackCallback.java:52) .556282-04:00] [app:] at org.candlepin.pinsetter.tasks.RefreshPoolsJob$$EnhancerByGuice$$c2e08334.execute(<generated>) .556285-04:00] [app:] at org.candlepin.pinsetter.core.TransactionalPinsetterJob.execute(TransactionalPinsetterJob.java:50) .556285-04:00] [app:] at org.quartz.core.JobRunShell.run(Unknown Source) .556287-04:00] [app:] at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(Unknown Source) .556548-04:00] [app:] aused by: java.sql.BatchUpdateException: Duplicate entry '3013983-master' for key 'subscriptionId' .556548-04:00] [app:] at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:2054) .556553-04:00] [app:] at com.mysql.jdbc.PreparedStatement.executeBatch(PreparedStatement.java:1467) .556553-04:00] [app:] at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:2429) .556556-04:00] [app:] ... 24 more .556556-04:00] [app:] aused by: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '3013983-master' for key 'subscriptionId' .556559-04:00] [app:] at sun.reflect.GeneratedConstructorAccessor698.newInstance(Unknown Source) .556559-04:00] [app:] at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) .556562-04:00] [app:] at java.lang.reflect.Constructor.newInstance(Constructor.java:532) .556562-04:00] [app:] at com.mysql.jdbc.Util.handleNewInstance(Util.java:411) .556565-04:00] [app:] at com.mysql.jdbc.Util.getInstance(Util.java:386) .556565-04:00] [app:] at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1040) .556638-04:00] [app:] at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4074) .556638-04:00] [app:] at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4006) .556643-04:00] [app:] at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2468) .556643-04:00] [app:] at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2629) .556730-04:00] [app:] at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2719) .556730-04:00] [app:] at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2155) .556735-04:00] [app:] at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2450) .556804-04:00] [app:] at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:2006) .556804-04:00] [app:] ... 26 more mysql> select * from cp_pool where subscriptionId = '3013983'; +----------------------------------+---------------------+---------------------+---------------+--------------------+----------------+---------------------+-----------+---------------------------------------------------+----------+----------------------+---------------------+----------------+----------------------------------+----------------------+--------------------+---------+-------------+------------------+--------------------+---------------+-------------------+ | id | created | updated | accountNumber | activeSubscription | contractNumber | endDate | productId | productName | quantity | restrictedToUsername | startDate | subscriptionId | owner_id | sourceEntitlement_id | subscriptionSubKey | version | orderNumber | derivedProductId | derivedProductName | sourceStackId | sourceConsumer_id | +----------------------------------+---------------------+---------------------+---------------+--------------------+----------------+---------------------+-----------+---------------------------------------------------+----------+----------------------+---------------------+----------------+----------------------------------+----------------------+--------------------+---------+-------------+------------------+--------------------+---------------+-------------------+ | 8a9bf98b4113267f01413145e3234705 | 2013-09-18 09:32:45 | 2013-09-18 09:32:45 | 5353302 | | 10274518 | 2014-09-17 23:59:59 | MCT0988 | Red Hat Enterprise Linux, Basic (up to 2 sockets) | 8 | NULL | 2013-09-18 00:00:00 | 3013983 | 8a9bf98b4113267f01413145cecf3e43 | NULL | derived | 0 | NULL | NULL | NULL | NULL | NULL | | 8a9bf98b4113267f01413145e2fa46df | 2013-09-18 09:32:45 | 2013-09-18 09:32:45 | 5353302 | | 10274518 | 2014-09-17 23:59:59 | MCT0988 | Red Hat Enterprise Linux, Basic (up to 2 sockets) | 2 | NULL | 2013-09-18 00:00:00 | 3013983 | 8a9bf98b4113267f01413145cecf3e43 | NULL | master | 0 | NULL | NULL | NULL | NULL | NULL | +----------------------------------+---------------------+---------------------+---------------+--------------------+----------------+---------------------+-----------+---------------------------------------------------+----------+----------------------+---------------------+----------------+----------------------------------+----------------------+--------------------+---------+-------------+------------------+--------------------+---------------+-------------------+ 2 rows in set (3.09 sec) mysql> select * from cp_owner where id = '8a9bf98b4113267f01413145cecf3e43'; +----------------------------------+---------------------+---------------------+-------------+---------+--------------+---------------+---------------------+-------------+ | id | created | updated | displayName | account | parent_owner | contentPrefix | defaultServiceLevel | upstream_id | +----------------------------------+---------------------+---------------------+-------------+---------+--------------+---------------+---------------------+-------------+ | 8a9bf98b4113267f01413145cecf3e43 | 2013-09-18 09:32:40 | 2013-09-18 09:32:40 | 7036698 | 7036698 | NULL | NULL | NULL | NULL | +----------------------------------+---------------------+---------------------+-------------+---------+--------------+---------------+---------------------+-------------+ 1 row in set (0.01 sec)
This is from a different run, but interesting that the cp_job table marks it as complete (3) rather than a 5. | refresh_pools_cc7ee66a-64b8-4e68-ae60-1eb9349d4317 | 2013-09-18 16:13:07 | 2013-09-18 16:16:09 | 2013-09-18 16:13:08 | java.sql.BatchUpdateException: Duplicate entry '3013988-master' for key 'subscriptionId' | 2013-09-18 16:13:07 | 3 | async group | candlepin_admin | 7036663 | 0 |
The manual solution to resolve this issue, is to delete the pools for the offending subscription, then to run a pool refresh.
Delete the pool or the outstanding entitlements? Also how exactly are you doing the delete? And when you mentioned manually triggering a refresh pools, how exactly is that being run?
Sorry confused issues, wrong comment above.
(For the record, this particular instance was in stage, I do not have the ability to delete pools in prod myself) Deleted the pool, no entitlements were deleted to the best of my knowledge. I used the candlepin api: DELETE /candlepin/pools/<pool_uuid> For the manual refresh, I again simply mean a direct call to api: PUT /candlepin/owners/<owner_key>/subscriptions?auto_create_owner=true
> BatchUpdateException: Duplicate entry '3013983-master' for key 'subscriptionId' Judging from this and the date posted, this problem is already solved. We don't use a unique constraint on subscriptionId/subscriptionKey. We probably should enforce uniqueness though, but they're nullable so it'll be a bigger change. If this is still occurring, please let me know.