Bug 1371412 - Failed to send info to Stage candlepin for libvirt local mode, it will show "RestlibException: Problem updating unit Consumer"
Summary: Failed to send info to Stage candlepin for libvirt local mode, it will show "...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: virt-who
Version: 7.0
Hardware: x86_64
OS: Linux
medium
medium
Target Milestone: rc
: ---
Assignee: Jiri Hnidek
QA Contact: Eko
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-08-30 07:39 UTC by Eko
Modified: 2019-10-28 07:21 UTC (History)
9 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2018-05-31 16:59:22 UTC
Target Upstream Version:


Attachments (Terms of Use)

Description Eko 2016-08-30 07:39:19 UTC
Description of problem:
run virt-who with libvirt local mode and against stage candlepin, send the json info failed, it will show "RestlibException: Problem updating unit Consumer<id=null, uuid=3c77cf50-1918-47b7-893b-a8f5502540c7, type=null, name=null> "

Version-Release number of selected component (if applicable):
virt-who-0.17-10.el7.noarch
subscription-manager-1.17.10-1.el7.x86_64
python-rhsm-1.17.6-1.el7.x86_64


How reproducible:
50%

Steps to Reproduce:
1. register host to stage candlepin

2. run virt-who for libvirt local mode
# virt-who -d 
2016-08-30 03:38:17,437 [virtwho.init INFO] MainProcess(1170):MainThread @main.py:main:153 - No configurations found, using libvirt as backend
2016-08-30 03:38:17,438 [virtwho.init INFO] MainProcess(1170):MainThread @main.py:main:160 - Using configuration "env/cmdline" ("libvirt" mode)
2016-08-30 03:38:17,438 [virtwho.init INFO] MainProcess(1170):MainThread @main.py:main:162 - Using reporter_id='hp-z220-10.qe.lab.eng.nay.redhat.com-f473adebc5ff4338a9d660b84d08a598'
2016-08-30 03:38:17,439 [virtwho.main DEBUG] MainProcess(1170):MainThread @executor.py:run:171 - Starting infinite loop with 60 seconds interval
2016-08-30 03:38:17,468 [virtwho.env_cmdline DEBUG] Libvirtd-1(1177):MainThread @virt.py:run:364 - Virt backend 'env/cmdline' started
2016-08-30 03:38:17,469 [virtwho.env_cmdline INFO] Libvirtd-1(1177):MainThread @libvirtd.py:_connect:157 - Using libvirt url: ""
2016-08-30 03:38:17,470 [virtwho.env_cmdline DEBUG] Libvirtd-1(1177):MainThread @libvirtd.py:_listDomains:245 - Libvirt domains found: 5e815888-ae08-4de0-831c-de43830adef1
2016-08-30 03:38:17,474 [virtwho.env_cmdline DEBUG] Libvirtd-1(1177):MainThread @virt.py:enqueue:357 - Report for config "env/cmdline" gathered, putting to queue for sending
2016-08-30 03:38:17,485 [virtwho.main DEBUG] MainProcess(1170):MainThread @subscriptionmanager.py:_connect:124 - Authenticating with certificate: /etc/pki/consumer/cert.pem
2016-08-30 03:38:18,688 [virtwho.main INFO] MainProcess(1170):MainThread @subscriptionmanager.py:sendVirtGuests:153 - Sending update in guests lists for config "env/cmdline": 1 guests found
2016-08-30 03:38:18,688 [virtwho.main DEBUG] MainProcess(1170):MainThread @subscriptionmanager.py:sendVirtGuests:154 - Domain info: [
    {
        "guestId": "5e815888-ae08-4de0-831c-de43830adef1", 
        "state": 1, 
        "attributes": {
            "active": 1, 
            "virtWhoType": "libvirt"
        }
    }
]
2016-08-30 03:38:20,824 [virtwho.main ERROR] MainProcess(1170):MainThread @executor.py:send:156 - Error in communication with subscription manager:
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/virtwho/executor.py", line 137, in send
    self._sendGuestList(report)
  File "/usr/lib/python2.7/site-packages/virtwho/executor.py", line 162, in _sendGuestList
    manager.sendVirtGuests(report, self.options)
  File "/usr/lib/python2.7/site-packages/virtwho/manager/subscriptionmanager/subscriptionmanager.py", line 158, in sendVirtGuests
    self.connection.updateConsumer(self.uuid(), guest_uuids=serialized_guests, hypervisor_id=report.hypervisor_id)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 1010, in updateConsumer
    ret = self.conn.request_put(method, params)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 703, in request_put
    return self._request("PUT", method, params)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 611, in _request
    self.validateResponse(result, request_type, handler)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 661, in validateResponse
    raise RestlibException(response['status'], error_msg, response.get('headers'))
RestlibException: Problem updating unit Consumer<id=null, uuid=f975d01c-fbd0-4797-af73-bbeaaa5b340c, type=null, name=null>
2016-08-30 03:38:20,825 [virtwho.main DEBUG] MainProcess(1170):MainThread @executor.py:send_report:108 - Report from "env/cmdline" failed to sent



Actual results:
failed to send, due to "RestlibException: Problem updating unit Consumer<id=null, uuid=f975d01c-fbd0-4797-af73-bbeaaa5b340c, type=null, name=null>"

Expected results:
it should be sent normally

Additional info:

Comment 1 Radek Novacek 2016-08-30 07:47:46 UTC
Sounds like server-side issue to me. Can you please attach logs from the candlepin?

Comment 2 Eko 2016-08-30 09:57:08 UTC
(In reply to Radek Novacek from comment #1)
> Sounds like server-side issue to me. Can you please attach logs from the
> candlepin?

Hi Radek,
it's not a satellite bug, it's related with stage candlepin, so we can't fetch the log message.

when I use another stage candlepin account testing, the json info can be sent normally, so I agree with you, it seems a candlepin bug

Comment 3 gaoshang 2016-09-01 06:48:36 UTC
This bug can be reproduced via following steps, I think it's related to virt-who remote libvirt mode.

1, prepare 2 hosts: hp-z220-07, hp-z220-08, configure authorized_keys in hp-z220-08 and copy to hp-z220-07 to enable remote libvirt mode.
    [root@hp-z220-08 ~]# ssh-keygen
    [root@hp-z220-08 ~]# ssh-copy-id -i ~/.ssh/id_rsa.pub hp-z220-07

2, register hp-z220-08 to stage candlepin, stop virt-who service and configure remote libvirt mode
    [root@hp-z220-08 ~]# subscription-manager register
    [root@hp-z220-08 ~]# systemctl stop virt-who.service
    [root@hp-z220-08 ~]#cat > /etc/virt-who.d/virt-who <<EOF
[libvirt]
type=libvirt
server=hp-z220-07.qe.lab.eng.nay.redhat.com
username=root
password=
owner=7970632
env=7970632

EOF

3, start virt-who service, check log message as follows, in stage candlepin web page, a hypervisor named "826c4f80-28ee-11e2-b149-b4b52fe0ce88" should be added.
    [root@hp-z220-08 ~]# cat /var/log/rhsm/rhsm.log
2016-09-01 01:58:25,733 [virtwho.init DEBUG] MainProcess(11029):MainThread @executor.py:__init__:65 - Using config named 'libvirt'
2016-09-01 01:58:25,734 [virtwho.init INFO] MainProcess(11029):MainThread @main.py:main:160 - Using configuration "libvirt" ("libvirt" mode)
2016-09-01 01:58:25,734 [virtwho.init INFO] MainProcess(11029):MainThread @main.py:main:162 - Using reporter_id='hp-z220-08.qe.lab.eng.nay.redhat.com-357d6baee46041ca8e1386179476e20d'
2016-09-01 01:58:25,736 [virtwho.main DEBUG] MainProcess(11029):MainThread @executor.py:run:171 - Starting infinite loop with 60 seconds interval
2016-09-01 01:58:25,768 [virtwho.libvirt DEBUG] Libvirtd-1(11039):MainThread @virt.py:run:364 - Virt backend 'libvirt' started
2016-09-01 01:58:25,769 [virtwho.libvirt INFO] Libvirtd-1(11039):MainThread @libvirtd.py:_get_url:125 - Protocol is not specified in libvirt url, using qemu+ssh://
2016-09-01 01:58:25,769 [virtwho.libvirt INFO] Libvirtd-1(11039):MainThread @libvirtd.py:_get_url:136 - Libvirt path is not specified in the url, using /system
2016-09-01 01:58:25,769 [virtwho.libvirt INFO] Libvirtd-1(11039):MainThread @libvirtd.py:_connect:157 - Using libvirt url: qemu+ssh://root.lab.eng.nay.redhat.com/system?no_tty=1
2016-09-01 01:58:26,005 [virtwho.libvirt DEBUG] Libvirtd-1(11039):MainThread @libvirtd.py:_listDomains:245 - Libvirt domains found: e6277d3f-705c-4425-91e0-057e5f627215, b6ef25af-b9fa-4f30-9476-66077aae3ced
2016-09-01 01:58:26,006 [virtwho.libvirt DEBUG] Libvirtd-1(11039):MainThread @virt.py:enqueue:357 - Report for config "libvirt" gathered, putting to queue for sending
2016-09-01 01:58:26,019 [virtwho.main DEBUG] MainProcess(11029):MainThread @subscriptionmanager.py:_connect:124 - Authenticating with certificate: /etc/pki/consumer/cert.pem
2016-09-01 01:58:27,441 [virtwho.main DEBUG] MainProcess(11029):MainThread @subscriptionmanager.py:hypervisorCheckIn:172 - Checking if server has capability 'hypervisor_async'
2016-09-01 01:58:28,859 [virtwho.main DEBUG] MainProcess(11029):MainThread @subscriptionmanager.py:hypervisorCheckIn:184 - Server does not have 'hypervisors_async' capability
2016-09-01 01:58:28,860 [virtwho.main INFO] MainProcess(11029):MainThread @subscriptionmanager.py:hypervisorCheckIn:195 - Sending update in hosts-to-guests mapping for config "libvirt": 1 hypervisors and 2 guests found
2016-09-01 01:58:28,860 [virtwho.main DEBUG] MainProcess(11029):MainThread @subscriptionmanager.py:hypervisorCheckIn:196 - Host-to-guest mapping: {
    "826c4f80-28ee-11e2-b149-b4b52fe0ce88": [
        {
            "guestId": "e6277d3f-705c-4425-91e0-057e5f627215", 
            "state": 5, 
            "attributes": {
                "active": 0, 
                "virtWhoType": "libvirt"
            }
        }, 
        {
            "guestId": "b6ef25af-b9fa-4f30-9476-66077aae3ced", 
            "state": 5, 
            "attributes": {
                "active": 0, 
                "virtWhoType": "libvirt"
            }
        }
    ]
}
2016-09-01 01:58:30,092 [virtwho.main DEBUG] MainProcess(11029):MainThread @executor.py:send_report:101 - Report for config "libvirt" sent

4, go to hp-z220-07, register to stage candlepin and start virt-who with libvirt local mode, this bug appears. if remove the hypervisor(826c4f80-28ee-11e2-b149-b4b52fe0ce88) generated in step 3 from stage web ui, the error will disappear.
    [root@hp-z220-07 ~]# cat /var/log/rhsm/rhsm.log

2016-09-01 01:56:54,971 [virtwho.init INFO] MainProcess(30833):MainThread @main.py:main:153 - No configurations found, using libvirt as backend
2016-09-01 01:56:54,971 [virtwho.init INFO] MainProcess(30833):MainThread @main.py:main:160 - Using configuration "env/cmdline" ("libvirt" mode)
2016-09-01 01:56:54,972 [virtwho.init INFO] MainProcess(30833):MainThread @main.py:main:162 - Using reporter_id='hp-z220-07.qe.lab.eng.nay.redhat.com-00e91b77dc3f4b439ea8e68bb1aa0727'
2016-09-01 01:56:54,973 [virtwho.main DEBUG] MainProcess(30833):MainThread @executor.py:run:171 - Starting infinite loop with 60 seconds interval
2016-09-01 01:56:55,002 [virtwho.env_cmdline DEBUG] Libvirtd-1(30840):MainThread @virt.py:run:364 - Virt backend 'env/cmdline' started
2016-09-01 01:56:55,003 [virtwho.env_cmdline INFO] Libvirtd-1(30840):MainThread @libvirtd.py:_connect:157 - Using libvirt url: ""
2016-09-01 01:56:55,005 [virtwho.env_cmdline DEBUG] Libvirtd-1(30840):MainThread @libvirtd.py:_listDomains:245 - Libvirt domains found: e6277d3f-705c-4425-91e0-057e5f627215, b6ef25af-b9fa-4f30-9476-66077aae3ced
2016-09-01 01:56:55,009 [virtwho.env_cmdline DEBUG] Libvirtd-1(30840):MainThread @virt.py:enqueue:357 - Report for config "env/cmdline" gathered, putting to queue for sending
2016-09-01 01:56:55,019 [virtwho.main DEBUG] MainProcess(30833):MainThread @subscriptionmanager.py:_connect:124 - Authenticating with certificate: /etc/pki/consumer/cert.pem
2016-09-01 01:56:56,440 [virtwho.main INFO] MainProcess(30833):MainThread @subscriptionmanager.py:sendVirtGuests:153 - Sending update in guests lists for config "env/cmdline": 2 guests found
2016-09-01 01:56:56,440 [virtwho.main DEBUG] MainProcess(30833):MainThread @subscriptionmanager.py:sendVirtGuests:154 - Domain info: [
    {
        "guestId": "b6ef25af-b9fa-4f30-9476-66077aae3ced", 
        "state": 5, 
        "attributes": {
            "active": 0, 
            "virtWhoType": "libvirt"
        }
    }, 
    {
        "guestId": "e6277d3f-705c-4425-91e0-057e5f627215", 
        "state": 5, 
        "attributes": {
            "active": 0, 
            "virtWhoType": "libvirt"
        }
    }
]
2016-09-01 01:56:58,650 [virtwho.main ERROR] MainProcess(30833):MainThread @executor.py:send:156 - Error in communication with subscription manager:
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/virtwho/executor.py", line 137, in send
    self._sendGuestList(report)
  File "/usr/lib/python2.7/site-packages/virtwho/executor.py", line 162, in _sendGuestList
    manager.sendVirtGuests(report, self.options)
  File "/usr/lib/python2.7/site-packages/virtwho/manager/subscriptionmanager/subscriptionmanager.py", line 158, in sendVirtGuests
    self.connection.updateConsumer(self.uuid(), guest_uuids=serialized_guests, hypervisor_id=report.hypervisor_id)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 1010, in updateConsumer
    ret = self.conn.request_put(method, params)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 703, in request_put
    return self._request("PUT", method, params)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 611, in _request
    self.validateResponse(result, request_type, handler)
  File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 661, in validateResponse
    raise RestlibException(response['status'], error_msg, response.get('headers'))
RestlibException: Problem updating unit Consumer<id=null, uuid=46733c6f-b52d-49a3-be0b-a28a70e48e6b, type=null, name=null>

Comment 5 Chris Snyder 2016-09-30 15:40:39 UTC
This looks to be an issue with reporting a hypervisor in both libvirt remote and local modes because they report different uuids.

1) Make sure that libvirt local mode and libvirt remote mode return the same UUID from virt-who

2) Make sure subscription-manager is using the same method as virt-who to get the UUID (Thus ensuring they are the same).

Comment 7 Liushihui 2016-12-20 08:38:42 UTC
It still exist on RHEL-6.9-20161216.1 against stage candlepin.

Comment 8 Liushihui 2017-01-25 00:57:13 UTC
It still exist on RHEL-6.9-20170118.0 against stage candlepin. virt-who's version is virt-who-0.18-2.el6.noarch.

Comment 9 Jiri Hnidek 2017-06-07 11:54:00 UTC
I cannot reproduce this bug with current version of virt-who and subscription-manager. Can anybody confirm?

Comment 10 Chris Snyder 2017-06-07 14:50:23 UTC
I am able to reproduce this against virt-who master.

An alternate way to reproduce can be found below:

0) Start on an unregistered system that has virtual guests (we'll call this HOST) with no prior virt-who configuration (/etc/virt-who.d/ should be empty)

1) Save the following (set owner/env/rhsm* as needed, less the triple quotes) as "remote_libvirt.conf" in your home directory:

"""
[remote_libvirt]
type=libvirt
server=qemu:///system
owner=admin
env=admin
rhsm_hostname=localhost
rhsm_port=8443
rhsm_username=admin
rhsm_password=admin
rhsm_prefix=/candlepin
"""

2) Save the following as "local_libvirt.conf" (update owner/env/rhsm* as needed) in your home directory: 

"""
[local_libvirt]
type=libvirt
owner=admin
env=admin
rhsm_hostname=localhost
rhsm_port=8443
rhsm_username=admin
rhsm_password=admin
rhsm_prefix=/candlepin
"""

3) Run virt-who: `virt-who -o -d -c ~/remote_libvirt.conf`

4) Observe that the report appears to have been successful

5) Run virt-who again this time with the local_libvirt configuration: `virt-who -o -d -c ~/local_libvirt.conf`

6) Observe the following line in the output:
"""
RestlibException: Problem updating unit Consumer [id: null, uuid: c08ec850-01cc-4825-9ccc-ef58c94d4106, consumerType: null, name: null]
"""

Also, I am moving this issue to 7.5 as this is not a blocking issue for 7.4

Comment 11 Chris Snyder 2017-06-08 15:20:51 UTC
Please note there is a missing step in my repro steps above.

Step 4 should include the following:

Register the system using subscription-manager to the same organization the remote libvirt configuration is pointing to.

Comment 12 Jiri Hnidek 2017-06-08 16:09:47 UTC
I can confirm this behavior. Just note the HOST have to be registered using subscription-manager between step 4 and 5. Otherwise virt-who will not be able to communicate with candlepin server. I run sub-man with following parameters:

$ subscription-manager register --username=admin --password=admin --org=admin

BTW: this error appeared in candlepin.log file after RestlibException was raised by virt-who:

2017-06-08 11:35:00,053 [thread=QuartzScheduler_Worker-11] [job=SweepBarJob-b6e994da-452c-455e-9322-a0d7f0a01ffb, org=, csid=] INFO  org.candlepin.pinsetter.tasks.KingpinJob - Starting job: org.candlepin.pinsetter.tasks.SweepBarJob
2017-06-08 11:35:00,055 [thread=QuartzScheduler_Worker-11] [job=SweepBarJob-b6e994da-452c-455e-9322-a0d7f0a01ffb, org=, csid=] INFO  org.candlepin.pinsetter.tasks.KingpinJob - Job completed: time=2
2017-06-08 11:36:03,745 [thread=http-bio-8443-exec-7] [req=922b2231-fded-46f0-9e5d-18ab9864a52b, org=, csid=] INFO  org.candlepin.common.filter.LoggingFilter - Request: verb=GET, uri=/candlepin/status/
2017-06-08 11:36:03,747 [thread=http-bio-8443-exec-7] [req=922b2231-fded-46f0-9e5d-18ab9864a52b, org=, csid=] INFO  org.candlepin.common.filter.LoggingFilter - Response: status=200, content-type="application/json", time=2
2017-06-08 11:36:03,778 [thread=http-bio-8443-exec-11] [req=4851a4b0-ff3b-46e3-9b04-8ee915dc840c, org=, csid=] INFO  org.candlepin.common.filter.LoggingFilter - Request: verb=GET, uri=/candlepin/
2017-06-08 11:36:03,779 [thread=http-bio-8443-exec-11] [req=4851a4b0-ff3b-46e3-9b04-8ee915dc840c, org=, csid=] INFO  org.candlepin.common.filter.LoggingFilter - Response: status=200, content-type="application/json", time=1
2017-06-08 11:36:03,796 [thread=http-bio-8443-exec-12] [req=11cf3e5e-50d9-4121-aa81-87539793c616, org=, csid=] INFO  org.candlepin.common.filter.LoggingFilter - Request: verb=PUT, uri=/candlepin/consumers/640029be-435d-4c42-b876-e3e21e25acdb
2017-06-08 11:36:03,906 [thread=http-bio-8443-exec-12] [req=11cf3e5e-50d9-4121-aa81-87539793c616, org=admin, csid=] WARN  org.hibernate.engine.jdbc.spi.SqlExceptionHelper - SQL Error: 0, SQLState: 23505
2017-06-08 11:36:03,906 [thread=http-bio-8443-exec-12] [req=11cf3e5e-50d9-4121-aa81-87539793c616, org=admin, csid=] ERROR org.hibernate.engine.jdbc.spi.SqlExceptionHelper - ERROR: duplicate key value violates unique constraint "cp_consumer_hypervisor_ukey"
  Detail: Key (hypervisor_id, owner_id)=(fb9d1281-53cc-11cb-9a33-8043c5f45d9d, 4028fa7a5c884ac9015c884cfe530004) already exists.
2017-06-08 11:36:03,907 [thread=http-bio-8443-exec-12] [req=11cf3e5e-50d9-4121-aa81-87539793c616, org=admin, csid=] ERROR org.candlepin.resource.ConsumerResource - Problem updating unit:
javax.persistence.PersistenceException: org.hibernate.exception.ConstraintViolationException: could not execute statement
	at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1692) ~[hibernate-entitymanager-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1602) ~[hibernate-entitymanager-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1608) ~[hibernate-entitymanager-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.jpa.spi.AbstractEntityManagerImpl.flush(AbstractEntityManagerImpl.java:1303) ~[hibernate-entitymanager-5.1.1.Final.jar:5.1.1.Final]
	at org.candlepin.model.AbstractHibernateCurator.flush(AbstractHibernateCurator.java:554) ~[AbstractHibernateCurator.class:na]
	at org.candlepin.model.AbstractHibernateCurator.save(AbstractHibernateCurator.java:549) ~[AbstractHibernateCurator.class:na]
	at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(JpaLocalTxnInterceptor.java:58) ~[guice-persist-3.0.jar:na]
	at org.candlepin.model.ConsumerCurator.update(ConsumerCurator.java:413) ~[ConsumerCurator.class:na]
	at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(JpaLocalTxnInterceptor.java:58) ~[guice-persist-3.0.jar:na]
	at org.candlepin.model.ConsumerCurator.update(ConsumerCurator.java:363) ~[ConsumerCurator.class:na]
	at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(JpaLocalTxnInterceptor.java:58) ~[guice-persist-3.0.jar:na]
	at org.candlepin.resource.ConsumerResource.updateConsumer(ConsumerResource.java:1030) ~[ConsumerResource.class:na]
	at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(JpaLocalTxnInterceptor.java:66) ~[guice-persist-3.0.jar:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_131]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_131]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_131]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_131]
	at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:137) [resteasy-jaxrs-3.0.10.Final.jar:na]
	at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:296) [resteasy-jaxrs-3.0.10.Final.jar:na]
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:250) [resteasy-jaxrs-3.0.10.Final.jar:na]
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:237) [resteasy-jaxrs-3.0.10.Final.jar:na]
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:356) [resteasy-jaxrs-3.0.10.Final.jar:na]
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:179) [resteasy-jaxrs-3.0.10.Final.jar:na]
	at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:220) [resteasy-jaxrs-3.0.10.Final.jar:na]
	at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56) [resteasy-jaxrs-3.0.10.Final.jar:na]
	at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51) [resteasy-jaxrs-3.0.10.Final.jar:na]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:731) [tomcat-servlet-3.0-api.jar:na]
	at com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:263) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:178) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.ManagedServletPipeline.service(ManagedServletPipeline.java:91) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:62) [guice-servlet-3.0.jar:na]
	at org.candlepin.servlet.filter.EventFilter.doFilter(EventFilter.java:61) [EventFilter.class:na]
	at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0.jar:na]
	at org.candlepin.servlet.filter.ContentTypeHackFilter.doFilter(ContentTypeHackFilter.java:58) [ContentTypeHackFilter.class:na]
	at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0.jar:na]
	at org.candlepin.common.filter.LoggingFilter.doFilter(LoggingFilter.java:112) [candlepin-common-2.0.3.jar:]
	at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0.jar:na]
	at org.candlepin.servlet.filter.CandlepinPersistFilter.doFilter(CandlepinPersistFilter.java:48) [CandlepinPersistFilter.class:na]
	at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0.jar:na]
	at org.candlepin.servlet.filter.CandlepinScopeFilter.doFilter(CandlepinScopeFilter.java:68) [CandlepinScopeFilter.class:na]
	at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:118) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:113) [guice-servlet-3.0.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) [catalina.jar:7.0.69]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [catalina.jar:7.0.69]
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220) [catalina.jar:7.0.69]
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122) [catalina.jar:7.0.69]
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505) [catalina.jar:7.0.69]
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169) [catalina.jar:7.0.69]
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [catalina.jar:7.0.69]
	at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:956) [catalina.jar:7.0.69]
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116) [catalina.jar:7.0.69]
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:436) [catalina.jar:7.0.69]
	at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1078) [tomcat-coyote.jar:7.0.69]
	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625) [tomcat-coyote.jar:7.0.69]
	at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316) [tomcat-coyote.jar:7.0.69]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_131]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_131]
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-coyote.jar:7.0.69]
	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_131]
Caused by: org.hibernate.exception.ConstraintViolationException: could not execute statement
	at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:112) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:111) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:97) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:207) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:45) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2932) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3432) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:89) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:582) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:456) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1295) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.jpa.spi.AbstractEntityManagerImpl.flush(AbstractEntityManagerImpl.java:1300) ~[hibernate-entitymanager-5.1.1.Final.jar:5.1.1.Final]
	... 61 common frames omitted
Caused by: org.postgresql.util.PSQLException: ERROR: duplicate key value violates unique constraint "cp_consumer_hypervisor_ukey"
  Detail: Key (hypervisor_id, owner_id)=(fb9d1281-53cc-11cb-9a33-8043c5f45d9d, 4028fa7a5c884ac9015c884cfe530004) already exists.
	at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2102) ~[postgresql-9.0-801.jdbc4.jar:na]
	at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1835) ~[postgresql-9.0-801.jdbc4.jar:na]
	at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:257) ~[postgresql-9.0-801.jdbc4.jar:na]
	at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:500) ~[postgresql-9.0-801.jdbc4.jar:na]
	at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:388) ~[postgresql-9.0-801.jdbc4.jar:na]
	at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:334) ~[postgresql-9.0-801.jdbc4.jar:na]
	at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:384) ~[c3p0-0.9.5.2.jar:0.9.5.2]
	at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:204) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	... 71 common frames omitted
2017-06-08 11:36:03,911 [thread=http-bio-8443-exec-12] [req=11cf3e5e-50d9-4121-aa81-87539793c616, org=admin, csid=] WARN  org.candlepin.audit.EventSinkImpl - Rolling back hornetq transaction.
2017-06-08 11:36:03,947 [thread=http-bio-8443-exec-12] [req=11cf3e5e-50d9-4121-aa81-87539793c616, org=admin, csid=] INFO  org.candlepin.common.filter.LoggingFilter - Response: status=400, content-type="application/json", time=151
2017-06-08 11:40:00,012 [thread=QuartzScheduler_Worker-10] [job=SweepBarJob-b6e994da-452c-455e-9322-a0d7f0a01ffb, org=, csid=] INFO  org.candlepin.pinsetter.tasks.KingpinJob - Starting job: org.candlepin.pinsetter.tasks.SweepBarJob
2017-06-08 11:40:00,013 [thread=QuartzScheduler_Worker-10] [job=SweepBarJob-b6e994da-452c-455e-9322-a0d7f0a01ffb, org=, csid=] INFO  org.candlepin.pinsetter.tasks.KingpinJob - Job completed: time=1
2017-06-08 11:45:00,053 [thread=QuartzScheduler_Worker-13] [job=SweepBarJob-b6e994da-452c-455e-9322-a0d7f0a01ffb, org=, csid=] INFO  org.candlepin.pinsetter.tasks.KingpinJob - Starting job: org.candlepin.pinsetter.tasks.SweepBarJob
2017-06-08 11:45:00,054 [thread=QuartzScheduler_Worker-13] [job=SweepBarJob-b6e994da-452c-455e-9322-a0d7f0a01ffb, org=, csid=] INFO  org.candlepin.pinsetter.tasks.KingpinJob - Job completed: time=1
2017-06-08 11:50:00,015 [thread=QuartzScheduler_Worker-12] [job=SweepBarJob-b6e994da-452c-455e-9322-a0d7f0a01ffb, org=, csid=] INFO  org.candlepin.pinsetter.tasks.KingpinJob - Starting job: org.candlepin.pinsetter.tasks.SweepBarJob

Comment 13 William Poteat 2018-04-06 19:46:34 UTC
Liklely fixed by the solution to BZ 1365248.

Needs to be confirmed.

Comment 14 Chris "Ceiu" Rog 2018-05-31 16:59:22 UTC
This appears to be fixed in the current build of Candlepin 0.9.54


Note You need to log in before you can comment on or make changes to this bug.