| Summary: | /var/lib/candlepin/candlepin-crl.crl is growing with duplicate Serials | ||
|---|---|---|---|
| Product: | [Community] Candlepin | Reporter: | John Sefler <jsefler> |
| Component: | candlepin | Assignee: | Alex Wood <awood> |
| Status: | CLOSED CURRENTRELEASE | QA Contact: | Katello QA List <katello-qa-list> |
| Severity: | high | Docs Contact: | |
| Priority: | unspecified | ||
| Version: | 2.0 | CC: | awood, redakkan, skallesh, vrjain |
| Target Milestone: | --- | ||
| Target Release: | --- | ||
| Hardware: | Unspecified | ||
| OS: | Unspecified | ||
| Whiteboard: | |||
| Fixed In Version: | candlepin-2.0.22-1 | Doc Type: | If docs needed, set a value |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2017-01-20 12:25:58 UTC | Type: | Bug |
| Regression: | --- | Mount Type: | --- |
| Documentation: | --- | CRM: | |
| Verified Versions: | Category: | --- | |
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
| Cloudforms Team: | --- | Target Upstream Version: | |
It looks like the issue is that when the CrlFileUtil class marks a CertificateSerial as "collected" that change is not getting persisted back to the database. The end result is a serial number that always looks like it's supposed to go on the CRL and thus gets added multiple times. This bug is actually a regression. With git bisect, I tracked this back to 76d56afc817de98a2788fbd42f9b8626b7eb8642 where we upgraded to Hibernate 5.1.1. commit 529e35f6b100edb2d97638a6d7ab371cf3da114e
Author: Alex Wood <awood>
Date: Wed Nov 30 10:59:17 2016 -0500
1399356: No transaction in syncCRLWithDB caused immediate rollback
Futhermore, use EntityManager's flush instead of Session's flush so that
a missing transaction will cause a TransactionRequiredException to be
thrown instead of Session's flush which just fails silently.
|
Description of problem: After a subscription-manager client removes a consumed subscription from it's system, the corresponding entitlement serial is added by candlepin to a certificate revocation list (/var/lib/candlepin/candlepin-crl.crl). There is an ExpiredPoolsJob.schedule by which the list is updated. Once a serial is on the list, there should be no reason to append the same serial to the list. Unfortunately, this appears to be failing... The candlepin-crl.crl appears to be growing out of control with duplicate serial entries. In the reproducer steps, I'll attempt to demonstrate that the candlepin-crl.crl file is growing with duplicate serial entries every time the CertificateRevocationListTask.schedule triggers (which I've set to 2 minutes because I am too impatient to wait for the default - 1 hour?). Version-Release number of selected component (if applicable): [root@jsefler-candlepin candlepin]# git log | head -1 commit 69f7f5114a425513ec0fb2d2f61fca2010e9fb05 [root@jsefler-rhel6 ~]# subscription-manager version server type: This system is currently not registered. subscription management server: 2.0.21-1 subscription management rules: 5.20 subscription-manager: 1.18.4-1.el6 python-rhsm: 1.18.4-1.git.9.bd3c973.el6 How reproducible: Steps to Reproduce: ON CANDLEPIN SERVER... [root@jsefler-candlepin candlepin]# grep ExpiredPoolsJob /etc/candlepin/candlepin.conf pinsetter.org.candlepin.pinsetter.tasks.ExpiredPoolsJob.schedule=0 0/2 * * * ? Deploy an opremise candlepin from master with TESTDATA (Not shown) [root@jsefler-candlepin candlepin]# ls -lh /var/lib/candlepin/candlepin-crl.crl ls: cannot access /var/lib/candlepin/candlepin-crl.crl: No such file or directory ON SUBSCRIPTION_MANAGER CLIENT... [root@jsefler-rhel6 ~]# subscription-manager register --username=testuser1 --org=admin Registering to: jsefler-candlepin.usersys.redhat.com:8443/candlepin Password: The system has been registered with ID: 3ed4b727-5fe6-4a4e-a479-0693f6bf1a55 [root@jsefler-rhel6 ~]# subscription-manager list --avail --pool-only | tail -1 8a90860f58ac92500158ac9383530571 [root@jsefler-rhel6 ~]# subscription-manager attach --pool=8a90860f58ac92500158ac9383530571 Successfully attached a subscription for: Awesome OS with up to 4 virtual guests [root@jsefler-rhel6 ~]# subscription-manager list --consumed | grep Serial Serial: 6158032235693919443 [root@jsefler-rhel6 ~]# subscription-manager remove --serial=6158032235693919443 The entitlement server successfully removed these serial numbers: 6158032235693919443 1 local certificate has been deleted. ON CANDLEPIN SERVER... [root@jsefler-candlepin candlepin]# sleep 120 [root@jsefler-candlepin candlepin]# ls -lh /var/lib/candlepin/candlepin-crl.crl -rw-r--r--. 1 tomcat tomcat 690 Nov 28 15:32 /var/lib/candlepin/candlepin-crl.crl [root@jsefler-candlepin candlepin]# openssl crl -noout -text -in /var/lib/candlepin/candlepin-crl.crl | grep Serial Serial Number: 5575B9B113F0CCD3 [root@jsefler-candlepin candlepin]# [root@jsefler-candlepin candlepin]# sleep 120 [root@jsefler-candlepin candlepin]# ls -lh /var/lib/candlepin/candlepin-crl.crl -rw-r--r--. 1 tomcat tomcat 741 Nov 28 15:34 /var/lib/candlepin/candlepin-crl.crl [root@jsefler-candlepin candlepin]# openssl crl -noout -text -in /var/lib/candlepin/candlepin-crl.crl | grep Serial Serial Number: 5575B9B113F0CCD3 Serial Number: 5575B9B113F0CCD3 [root@jsefler-candlepin candlepin]# sleep 120 [root@jsefler-candlepin candlepin]# ls -lh /var/lib/candlepin/candlepin-crl.crl -rw-r--r--. 1 tomcat tomcat 798 Nov 28 15:36 /var/lib/candlepin/candlepin-crl.crl [root@jsefler-candlepin candlepin]# openssl crl -noout -text -in /var/lib/candlepin/candlepin-crl.crl | grep Serial Serial Number: 5575B9B113F0CCD3 Serial Number: 5575B9B113F0CCD3 Serial Number: 5575B9B113F0CCD3 [root@jsefler-candlepin candlepin]# Actual results: Notice above that after each two minutes, the candlepin-crl.crl grows in size with a duplicate entry for the serial that was just removed. Expected results: The candlepin-crl.crl list should not grow out of control with duplicate serials. Additional info: Here is the candlepin.log from the reproducer steps above [root@jsefler-candlepin ~]# tail -f /var/log/candlepin/candlepin.log 2016-11-28 15:30:41,232 [thread=http-bio-8443-exec-9] [req=a3b0402a-35e2-4055-8192-9e57d5a95c53, org=] INFO org.candlepin.common.filter.LoggingFilter - Request: verb=DELETE, uri=/candlepin/consumers/3ed4b727-5fe6-4a4e-a479-0693f6bf1a55/certificates/6158032235693919443 2016-11-28 15:30:41,375 [thread=http-bio-8443-exec-9] [req=a3b0402a-35e2-4055-8192-9e57d5a95c53, org=admin] INFO org.candlepin.controller.CandlepinPoolManager - Batch revoking 1 entitlements 2016-11-28 15:30:41,403 [thread=http-bio-8443-exec-9] [req=a3b0402a-35e2-4055-8192-9e57d5a95c53, org=admin] INFO org.candlepin.controller.CandlepinPoolManager - Starting batch delete of pools 2016-11-28 15:30:41,403 [thread=http-bio-8443-exec-9] [req=a3b0402a-35e2-4055-8192-9e57d5a95c53, org=admin] INFO org.candlepin.controller.CandlepinPoolManager - Starting batch delete of entitlements 2016-11-28 15:30:41,405 [thread=http-bio-8443-exec-9] [req=a3b0402a-35e2-4055-8192-9e57d5a95c53, org=admin] INFO org.candlepin.controller.CandlepinPoolManager - Starting delete flush 2016-11-28 15:30:41,406 [thread=http-bio-8443-exec-9] [req=a3b0402a-35e2-4055-8192-9e57d5a95c53, org=admin] INFO org.candlepin.controller.CandlepinPoolManager - All deletes flushed successfully 2016-11-28 15:30:41,408 [thread=http-bio-8443-exec-9] [req=a3b0402a-35e2-4055-8192-9e57d5a95c53, org=admin] INFO org.candlepin.controller.CandlepinPoolManager - Recomputing status for 1 consumers. 2016-11-28 15:30:41,425 [thread=http-bio-8443-exec-9] [req=a3b0402a-35e2-4055-8192-9e57d5a95c53, org=admin] INFO org.candlepin.controller.CandlepinPoolManager - All statuses recomputed. 2016-11-28 15:30:41,439 [thread=http-bio-8443-exec-9] [req=a3b0402a-35e2-4055-8192-9e57d5a95c53, org=admin] WARN org.candlepin.common.resteasy.filter.LinkHeaderResponseFilter - Method marked for pagination, but no page exists in the context. 2016-11-28 15:30:41,440 [thread=http-bio-8443-exec-9] [req=a3b0402a-35e2-4055-8192-9e57d5a95c53, org=admin] INFO org.candlepin.common.filter.LoggingFilter - Response: status=204, content-type="null", time=208 2016-11-28 15:30:41,539 [thread=http-bio-8443-exec-10] [req=68894b46-2aa4-4475-871e-90115f13e85a, org=] INFO org.candlepin.common.filter.LoggingFilter - Request: verb=GET, uri=/candlepin/consumers/3ed4b727-5fe6-4a4e-a479-0693f6bf1a55/certificates/serials 2016-11-28 15:30:41,624 [thread=http-bio-8443-exec-10] [req=68894b46-2aa4-4475-871e-90115f13e85a, org=admin] WARN org.candlepin.common.resteasy.filter.LinkHeaderResponseFilter - Method marked for pagination, but no page exists in the context. 2016-11-28 15:30:41,625 [thread=http-bio-8443-exec-10] [req=68894b46-2aa4-4475-871e-90115f13e85a, org=admin] INFO org.candlepin.common.filter.LoggingFilter - Response: status=200, content-type="application/json", time=86 2016-11-28 15:30:41,725 [thread=http-bio-8443-exec-1] [req=8d2ae360-a7a6-4164-92d0-2c08e7259d38, org=] INFO org.candlepin.common.filter.LoggingFilter - Request: verb=GET, uri=/candlepin/ 2016-11-28 15:30:41,726 [thread=http-bio-8443-exec-1] [req=8d2ae360-a7a6-4164-92d0-2c08e7259d38, org=] WARN org.candlepin.common.resteasy.filter.LinkHeaderResponseFilter - Method marked for pagination, but no page exists in the context. 2016-11-28 15:30:41,726 [thread=http-bio-8443-exec-1] [req=8d2ae360-a7a6-4164-92d0-2c08e7259d38, org=] INFO org.candlepin.common.filter.LoggingFilter - Response: status=200, content-type="application/json", time=1 2016-11-28 15:30:41,825 [thread=http-bio-8443-exec-7] [req=715e0713-1d4e-4f03-9d01-dab4e91a7676, org=] INFO org.candlepin.common.filter.LoggingFilter - Request: verb=GET, uri=/candlepin/consumers/3ed4b727-5fe6-4a4e-a479-0693f6bf1a55/content_overrides 2016-11-28 15:30:41,854 [thread=http-bio-8443-exec-7] [req=715e0713-1d4e-4f03-9d01-dab4e91a7676, org=] WARN org.candlepin.common.resteasy.filter.LinkHeaderResponseFilter - Method marked for pagination, but no page exists in the context. 2016-11-28 15:30:41,855 [thread=http-bio-8443-exec-7] [req=715e0713-1d4e-4f03-9d01-dab4e91a7676, org=] INFO org.candlepin.common.filter.LoggingFilter - Response: status=200, content-type="application/json", time=30 2016-11-28 15:30:41,960 [thread=http-bio-8443-exec-3] [req=c6cafd2c-d389-4b1d-9fbd-29e66299be00, org=] INFO org.candlepin.common.filter.LoggingFilter - Request: verb=GET, uri=/candlepin/consumers/3ed4b727-5fe6-4a4e-a479-0693f6bf1a55/compliance 2016-11-28 15:30:42,014 [thread=http-bio-8443-exec-3] [req=c6cafd2c-d389-4b1d-9fbd-29e66299be00, org=admin] WARN org.candlepin.common.resteasy.filter.LinkHeaderResponseFilter - Method marked for pagination, but no page exists in the context. 2016-11-28 15:30:42,015 [thread=http-bio-8443-exec-3] [req=c6cafd2c-d389-4b1d-9fbd-29e66299be00, org=admin] INFO org.candlepin.common.filter.LoggingFilter - Response: status=200, content-type="application/json", time=55 2016-11-28 15:30:42,361 [thread=http-bio-8443-exec-8] [req=26c59acd-192e-495e-a26a-d5cf0bbf3838, org=] INFO org.candlepin.common.filter.LoggingFilter - Request: verb=GET, uri=/candlepin/consumers/3ed4b727-5fe6-4a4e-a479-0693f6bf1a55/compliance 2016-11-28 15:30:42,415 [thread=http-bio-8443-exec-8] [req=26c59acd-192e-495e-a26a-d5cf0bbf3838, org=admin] WARN org.candlepin.common.resteasy.filter.LinkHeaderResponseFilter - Method marked for pagination, but no page exists in the context. 2016-11-28 15:30:42,415 [thread=http-bio-8443-exec-8] [req=26c59acd-192e-495e-a26a-d5cf0bbf3838, org=admin] INFO org.candlepin.common.filter.LoggingFilter - Response: status=200, content-type="application/json", time=54 2016-11-28 15:32:00,022 [thread=QuartzScheduler_Worker-10] [job=CertificateRevocationListTask-e1e06455-763a-493f-99e4-21f89f84edd6, org=] INFO org.candlepin.pinsetter.tasks.KingpinJob - Starting job: org.candlepin.pinsetter.tasks.CertificateRevocationListTask 2016-11-28 15:32:00,022 [thread=QuartzScheduler_Worker-10] [job=CertificateRevocationListTask-e1e06455-763a-493f-99e4-21f89f84edd6, org=] INFO org.candlepin.pinsetter.tasks.CertificateRevocationListTask - Executing CRL Job. CRL filePath=/var/lib/candlepin/candlepin-crl.crl 2016-11-28 15:32:00,030 [thread=QuartzScheduler_Worker-6] [job=ExpiredPoolsJob-74de093f-4552-44ce-93dd-2a026106039e, org=] INFO org.candlepin.pinsetter.tasks.KingpinJob - Starting job: org.candlepin.pinsetter.tasks.ExpiredPoolsJob 2016-11-28 15:32:00,035 [thread=QuartzScheduler_Worker-10] [job=CertificateRevocationListTask-e1e06455-763a-493f-99e4-21f89f84edd6, org=] INFO org.candlepin.pki.impl.BouncyCastlePKIUtility - Completed adding CRL numbers to the certificate. 2016-11-28 15:32:00,061 [thread=QuartzScheduler_Worker-10] [job=CertificateRevocationListTask-e1e06455-763a-493f-99e4-21f89f84edd6, org=] INFO org.candlepin.pinsetter.tasks.KingpinJob - Job completed: time=39 2016-11-28 15:32:00,064 [thread=QuartzScheduler_Worker-6] [job=ExpiredPoolsJob-74de093f-4552-44ce-93dd-2a026106039e, org=] INFO org.candlepin.pinsetter.tasks.KingpinJob - Job completed: time=34 2016-11-28 15:34:00,047 [thread=QuartzScheduler_Worker-15] [job=CertificateRevocationListTask-e1e06455-763a-493f-99e4-21f89f84edd6, org=] INFO org.candlepin.pinsetter.tasks.KingpinJob - Starting job: org.candlepin.pinsetter.tasks.CertificateRevocationListTask 2016-11-28 15:34:00,047 [thread=QuartzScheduler_Worker-15] [job=CertificateRevocationListTask-e1e06455-763a-493f-99e4-21f89f84edd6, org=] INFO org.candlepin.pinsetter.tasks.CertificateRevocationListTask - Executing CRL Job. CRL filePath=/var/lib/candlepin/candlepin-crl.crl 2016-11-28 15:34:00,048 [thread=QuartzScheduler_Worker-3] [job=ExpiredPoolsJob-74de093f-4552-44ce-93dd-2a026106039e, org=] INFO org.candlepin.pinsetter.tasks.KingpinJob - Starting job: org.candlepin.pinsetter.tasks.ExpiredPoolsJob 2016-11-28 15:34:00,147 [thread=QuartzScheduler_Worker-15] [job=CertificateRevocationListTask-e1e06455-763a-493f-99e4-21f89f84edd6, org=] INFO org.candlepin.pinsetter.tasks.KingpinJob - Job completed: time=100 2016-11-28 15:34:00,167 [thread=QuartzScheduler_Worker-3] [job=ExpiredPoolsJob-74de093f-4552-44ce-93dd-2a026106039e, org=] INFO org.candlepin.pinsetter.tasks.KingpinJob - Job completed: time=119 2016-11-28 15:35:00,029 [thread=QuartzScheduler_Worker-10] [job=SweepBarJob-5354f783-9540-4235-9e5a-93165263c0b8, org=] INFO org.candlepin.pinsetter.tasks.KingpinJob - Starting job: org.candlepin.pinsetter.tasks.SweepBarJob 2016-11-28 15:35:00,030 [thread=QuartzScheduler_Worker-10] [job=SweepBarJob-5354f783-9540-4235-9e5a-93165263c0b8, org=] INFO org.candlepin.pinsetter.tasks.KingpinJob - Job completed: time=1 2016-11-28 15:36:00,025 [thread=QuartzScheduler_Worker-12] [job=CertificateRevocationListTask-e1e06455-763a-493f-99e4-21f89f84edd6, org=] INFO org.candlepin.pinsetter.tasks.KingpinJob - Starting job: org.candlepin.pinsetter.tasks.CertificateRevocationListTask 2016-11-28 15:36:00,025 [thread=QuartzScheduler_Worker-12] [job=CertificateRevocationListTask-e1e06455-763a-493f-99e4-21f89f84edd6, org=] INFO org.candlepin.pinsetter.tasks.CertificateRevocationListTask - Executing CRL Job. CRL filePath=/var/lib/candlepin/candlepin-crl.crl 2016-11-28 15:36:00,051 [thread=QuartzScheduler_Worker-7] [job=ExpiredPoolsJob-74de093f-4552-44ce-93dd-2a026106039e, org=] INFO org.candlepin.pinsetter.tasks.KingpinJob - Starting job: org.candlepin.pinsetter.tasks.ExpiredPoolsJob 2016-11-28 15:36:00,055 [thread=QuartzScheduler_Worker-12] [job=CertificateRevocationListTask-e1e06455-763a-493f-99e4-21f89f84edd6, org=] INFO org.candlepin.pinsetter.tasks.KingpinJob - Job completed: time=30 2016-11-28 15:36:00,091 [thread=QuartzScheduler_Worker-7] [job=ExpiredPoolsJob-74de093f-4552-44ce-93dd-2a026106039e, org=] INFO org.candlepin.pinsetter.tasks.KingpinJob - Job completed: time=40