User:StasFomin/Bugs/SubscriptionManager/FK-problem-with-candlepin

Accidential bug on unsubscription

2016-04-01 22:25:10,609:DEBUG:VZSM> Runtime Error could not execute statement at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse:2,102

************************************************************************************************************



2016-04-02 04:25:08,376 [thread=http-bio-8443-exec-3] [req=1810e660-77cc-49b1-b298-c339740c50c5, org=TESTCOMPANY-1537242] ERROR org.hibernate.engine.jdbc.spi.SqlExceptionHelper - ERROR: update or delete on table "cp_consumer" violates foreign key constraint "fk_installed_product" on table "cp_installed_products"
  Detail: Key (id)=(ff80818153d4c6e10153d4c7fc4e001f) is still referenced from table "cp_installed_products".
2016-04-02 04:25:08,387 [thread=http-bio-8443-exec-3] [req=1810e660-77cc-49b1-b298-c339740c50c5, org=TESTCOMPANY-1537242] ERROR org.candlepin.common.exceptions.mappers.CandlepinExceptionMapper - Runtime Error could not execute statement at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse:2,102
org.hibernate.exception.ConstraintViolationException: could not execute statement
	at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:129) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:49) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:125) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:110) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:136) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:58) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3343) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3546) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.action.internal.EntityDeleteAction.execute(EntityDeleteAction.java:100) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.engine.spi.ActionQueue.execute(ActionQueue.java:377) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:369) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:293) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:339) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:52) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1234) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.ejb.AbstractEntityManagerImpl.flush(AbstractEntityManagerImpl.java:996) ~[hibernate-entitymanager-4.2.5.Final.jar:4.2.5.Final]
	at org.candlepin.model.AbstractHibernateCurator.flush(AbstractHibernateCurator.java:383) ~[AbstractHibernateCurator.class:na]
	at org.candlepin.model.AbstractHibernateCurator.save(AbstractHibernateCurator.java:378) ~[AbstractHibernateCurator.class:na]
	at org.candlepin.model.AbstractHibernateCurator.create(AbstractHibernateCurator.java:113) ~[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.delete(ConsumerCurator.java:112) ~[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.deleteConsumer(ConsumerResource.java:1247) ~[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_77]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_77]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_77]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_77]
	at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:137) ~[resteasy-jaxrs-3.0.6.Final.jar:na]
	at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:280) ~[resteasy-jaxrs-3.0.6.Final.jar:na]
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:234) ~[resteasy-jaxrs-3.0.6.Final.jar:na]
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:221) ~[resteasy-jaxrs-3.0.6.Final.jar:na]
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:356) [resteasy-jaxrs-3.0.6.Final.jar:na]
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:179) [resteasy-jaxrs-3.0.6.Final.jar:na]
	at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:220) [resteasy-jaxrs-3.0.6.Final.jar:na]
	at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56) [resteasy-jaxrs-3.0.6.Final.jar:na]
	at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51) [resteasy-jaxrs-3.0.6.Final.jar:na]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:727) [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:62) [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:90) [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.54]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [catalina.jar:7.0.54]
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220) [catalina.jar:7.0.54]
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122) [catalina.jar:7.0.54]
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:501) [catalina.jar:7.0.54]
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171) [catalina.jar:7.0.54]
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) [catalina.jar:7.0.54]
	at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:950) [catalina.jar:7.0.54]
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116) [catalina.jar:7.0.54]
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408) [catalina.jar:7.0.54]
	at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1040) [tomcat-coyote.jar:7.0.54]
	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:607) [tomcat-coyote.jar:7.0.54]
	at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:314) [tomcat-coyote.jar:7.0.54]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_77]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_77]
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-coyote.jar:7.0.54]
	at java.lang.Thread.run(Thread.java:745) [na:1.8.0_77]

Looks like concurrency problem because of my attempts to restore product certificates, not waiting for rhsmcertd.

    def restore_product_certificates(self):
        '''
        If host subscribed we get list of consumed products
        and get product certificates in 
        '''
        if not self.owner_id or not self.product_ids:
            return
 
        try:
            cfg = self.cfg
            owner_id = self.owner_id #pylint: disable=W0612
            consumer_cert_dir = cfg.get('rhsm', 'consumerCertDir')
            conn = connection.UEPConnection(
                host=cfg.get('server', 'hostname'),
                ssl_port=cfg.get_int('server', 'port'),
                handler=cfg.get('server', 'prefix'),
                proxy_hostname=cfg.get('server', 'proxy_hostname'),
                proxy_port=cfg.get_int('server', 'proxy_port'),
                proxy_user=cfg.get('server', 'proxy_user'),
                proxy_password=cfg.get('server', 'proxy_password'),
                cert_file=os.path.join(consumer_cert_dir, 'cert.pem'),
                key_file=os.path.join(consumer_cert_dir, 'key.pem'))
 
            product_cert_dir = cfg.get('rhsm', 'productCertDir')
            for svc_id in self.product_ids:
                prefix_ = os.path.join(product_cert_dir, svc_id)
                cert_filename = prefix_  + '.pem'
                key_filename = prefix_  + '-key.pem'
                if not (os.path.exists(cert_filename) and
                        os.path.exists(key_filename)):
                    cmd = '/owners/%(owner_id)s/products/%(svc_id)s/certificate' % vars()
                    self.log.debug(cmd)
                    res = conn.conn.request_get(cmd)
                    self.log.debug(res)
                    if 'cert' in res and 'key' in res:
                        cert = res['cert']
                        key = res['key']
                        self.log.info("Getting certs for SVC Product " + svc_id)
                        prefix_ = os.path.join(consumer_cert_dir, svc_id)
                        str2file(cert, cert_filename)
                        str2file(key, key_filename)
        except Exception as ex_:
            error_msg = '\n'.join([str(ex_), traceback.format_exc()])
            self.log.error(error_msg)
            return False
        return True

Without calling this function looks the problem do not occured.

Why I am getting product certificates because I try to use autohealing mechanism of rhsmcertd (for autoattaching new pool for the products)

[2016-02-01 21:09:07] <awood> so subscription-manager monitors a certain directory for product certificates.  And it uses those product certificates when it tries to heal itself (e.g. a pool it's using expires and it needs to get a new pool)
[2016-02-01 21:09:27] <awood> Candlepin can actually generate those product certificates and return them via a API call
[2016-02-01 21:10:25] <awood> so you could create the product, get the product certificate, and then install it in on the client.  (subscription-manager does have ways to auto-install product certificates but that's a little advanced and maybe we can cross that bridge when we come to it)
[2016-02-01 21:11:06] <awood> then rhsmcertd runs as a daemon trying to keep the clients subscriptions always up to date
[2016-02-01 21:11:45] <awood> so we can try a little experiment where you create a product cert, install it on a client, revoke one pool, create another and see if rhsmcertd moves the client to the new pool
[2016-02-01 21:17:11] <awood> the product certificates go into /etc/pki/product
[2016-02-01 21:17:54] <awood> the easiest way to deliver the product certificates might be via RPM
[2016-02-01 21:19:20] <awood> you can get the product certificate via GET /product/{product_id}/certificate

So actually, I need safe way to get this certs.