+++ This bug was initially created as a clone of Bug #1766345 +++
When processing a hypervisor checkin candlepin errors out with a Duplicate entry 'xxxxxxxxx-8a85f981483ab18501484267224f7a0d' for key 'cp_consumer_hypervisor_ukey'
I obfuscated that entry a little bit but many more like it can be found using a splunk search of `candlepin_hosts(env=prod)` 'cp_consumer_hypervisor_ukey'
Full stack trace is:
2019-10-28 18:32:44.740+0000 [thread=ITClusteredScheduler_Worker-2] [job=hypervisor_update_19d0696e-1eef-4835-8571-67c79fe1189a, org=XXXXX, csid=] ERROR org.candlepin.pinsetter.core.PinsetterJobListener - Job [hypervisor_update_19d0696e-1eef-4835-8571-67c79fe1189a] failed.
org.quartz.JobExecutionException: Error while committing the transaction
at org.candlepin.pinsetter.tasks.HypervisorUpdateJob.toExecute(HypervisorUpdateJob.java:194)
at org.candlepin.pinsetter.tasks.KingpinJob.execute(KingpinJob.java:114)
at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)
Caused by: javax.persistence.RollbackException: Error while committing the transaction
at org.hibernate.internal.ExceptionConverterImpl.convertCommitException(ExceptionConverterImpl.java:81)
at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:107)
at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(JpaLocalTxnInterceptor.java:91)
at org.candlepin.pinsetter.tasks.HypervisorUpdateJob.toExecute(HypervisorUpdateJob.java:167)
... 3 common frames omitted
Caused by: javax.persistence.PersistenceException: org.hibernate.exception.ConstraintViolationException: could not execute statement
at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:154)
at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:181)
at org.hibernate.internal.ExceptionConverterImpl.convertCommitException(ExceptionConverterImpl.java:65)
... 6 common frames omitted
Caused by: org.hibernate.exception.ConstraintViolationException: could not execute statement
at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:59)
at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42)
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113)
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99)
at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:178)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3358)
at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:3231)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3632)
at org.hibernate.action.internal.EntityUpdateAction.execute(EntityUpdateAction.java:146)
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604)
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:478)
at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:356)
at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1454)
at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:511)
at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3283)
at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2479)
at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:473)
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:178)
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$300(JdbcResourceLocalTransactionCoordinatorImpl.java:39)
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:271)
at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:104)
... 5 common frames omitted
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '-8a85f981483ab18501484267224f7a0d' for key 'cp_consumer_hypervisor_ukey'
at sun.reflect.GeneratedConstructorAccessor202.newInstance(Unknown Source)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
at com.mysql.jdbc.Util.getInstance(Util.java:386)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1041)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4190)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4122)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2570)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2731)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2818)
at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2157)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2460)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2377)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2361)
at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:462)
at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:175)
... 22 common frames omitted
--- Additional comment from William Poteat on 2019-10-29 19:03:06 UTC ---
Can you please pass along the version of virt-who that is being used by the org that results in this error?
--- Additional comment from Akash on 2019-10-30 07:30:03 UTC ---
Hi William,
Customer is using latest version of the virt-who package as below,
virt-who-0.24.7-1.el7.noarch
Regards,
Akash
--- Additional comment from William Poteat on 2019-10-30 21:07:49 UTC ---
The debugging output I received in the email from Sunpreet Bhamrah dated 10/25 looks like this:
{
"hypervisors": [
{
"uuid":"spcsocc07h06.css.id.ohio.gov",
"guests":[
{
"guestId":"42358e75-a66c-52c6-1a19-e3efd697a788",
"state":1,
"attributes":{
"active":1,
"virtWhoType":"esx"
}
},
And 0.24.7 looks like this:
{
"hypervisors": [
{
"hypervisorId": {
"hypervisorId": "esxi5-1.sat6.gsslab.pnq.redhat.com"
},
"name": "esxi5-1.sat6.gsslab.pnq.redhat.com",
"guestIds": [
{
"guestId": "42133a09-0ec9-f1c4-5101-d36b3ecee2b5",
"state": 1,
"attributes": {
"active": 1,
"virtWhoType": "esx"
}
},
Can we please have the debugging output from the customer as it is running now? Please attach it to the BZ.
This will help because the former is debugging output that does not show the exact data sent to the server. It is from an earlier version.
The latter matches exactly what is sent. Please confirm the structure of the json before attaching.
--- Additional comment from Ramesh kumar on 2019-10-31 14:20:29 UTC ---
Hello,
As requested, latest output of virt-who debug execution is attached to Bugzilla. File name: debugvirt-who.txt.
Kindly check and assist.
Thanks.
--- Additional comment from Akash on 2019-11-08 15:14:22 UTC ---
1. virt-who debug from the customer
2. Screenshot from the vCenter for Guest-Host mapping.
3. Screenshot from the Customer Portal for this Machine named 'cbanssbapp1'
--- Additional comment from Akash on 2019-11-08 15:14:57 UTC ---
Hi William,
Here is the scenario from Today's logs from Customer.
- Customer have migrated the machine named 'cbanssbapp1' from hypervisor named 'spcsocc12h02' to 'spcsocc12h03'.
The portal still reports it as being attached to spcsocc12h01.
- The UUID of this machine of 'cbanssbapp1' is 422e2d0d-1e3b-974b-b19a-17253619e539
[root@cbanssbapp1 ~]# subscription-manager facts | grep -i uuid
dmi.system.uuid: 422e2d0d-1e3b-974b-b19a-17253619e539
virt.uuid: 422e2d0d-1e3b-974b-b19a-17253619e539
- The Guest-Host mapping shows correct as below,
{
"hypervisorId": {
"hypervisorId": "spcsocc12h03.css.id.ohio.gov"
},
"name": "spcsocc12h03.css.id.ohio.gov",
"guestIds": [
{
"guestId": "422e2d0d-1e3b-974b-b19a-17253619e539",
"state": 1,
"attributes": {
"active": 1,
"virtWhoType": "esx"
}
}
--------------------------------------------------------------------
- Additional Data : Bug-1766345-Data-Nov-8.tar.xz
1. virt-who debug from the customer
2. Screenshot from the vCenter for Guest-Host mapping.
3. Screenshot from the Customer Portal for this Machine named 'cbanssbapp1'
Thank you !
Regards,
Akash