Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1840823

Summary: [candlepin] Unable to import subscription manifest in large environment (60K+ consumers/hosts)
Product: [Community] Candlepin (Migrated to Jira) Reporter: Chris "Ceiu" Rog <crog>
Component: candlepinAssignee: candlepin-bugs
Status: CLOSED CURRENTRELEASE QA Contact:
Severity: high Docs Contact:
Priority: unspecified    
Version: 2.9CC: bcourt, ltran, mmccune, ojanus, redakkan, skallesh
Target Milestone: ---Keywords: PrioBumpField
Target Release: 2.9   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: candlepin-2.9.28-1 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: 1840805
: 1840850 (view as bug list) Environment:
Last Closed: 2020-06-09 08:37:53 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On: 1840850, 1841596, 1841598    
Bug Blocks: 1840805    

Description Chris "Ceiu" Rog 2020-05-27 16:38:58 UTC 
+++ This bug was initially created as a clone of Bug #1840805 +++

In one of our large customer environments we are completely unable to import new subscriptions due to an error during the transaction:

2020-05-22 11:56:13,039 [thread=http-bio-8443-exec-7] [req=eb941534-31bd-4116-a687-3263630c82f2, org=ExampleTech, csid=] INFO  org.candlepin.policy.js.pool.PoolRules - Checking if bonus pools need to be created for pool: Pool [id=null, type=NORMAL, product=ESA0001, productName=Red Hat Enterprise Linux, Premium (One Year, Enterprise Program), quantity=50000]
2020-05-22 11:56:13,110 [thread=http-bio-8443-exec-7] [req=eb941534-31bd-4116-a687-3263630c82f2, org=ExampleTech, csid=] INFO  org.candlepin.controller.CandlepinPoolManager - Attempting to delete 4 pools...
2020-05-22 11:56:13,110 [thread=http-bio-8443-exec-7] [req=eb941534-31bd-4116-a687-3263630c82f2, org=ExampleTech, csid=] INFO  org.candlepin.controller.CandlepinPoolManager - Fetching related pools and entitlements...
2020-05-22 11:56:13,807 [thread=http-bio-8443-exec-7] [req=eb941534-31bd-4116-a687-3263630c82f2, org=ExampleTech, csid=] INFO  org.candlepin.controller.CandlepinPoolManager - Locked 4 pools for deletion...
2020-05-22 11:57:42,097 [thread=http-bio-8443-exec-7] [req=eb941534-31bd-4116-a687-3263630c82f2, org=ExampleTech, csid=] INFO  org.candlepin.controller.CandlepinPoolManager - Revoking 56323 entitlements...
2020-05-22 11:58:28,327 [thread=http-bio-8443-exec-7] [req=eb941534-31bd-4116-a687-3263630c82f2, org=ExampleTech, csid=] WARN  org.hibernate.engine.jdbc.spi.SqlExceptionHelper - SQL Error: 0, SQLState: 08006
2020-05-22 11:58:28,327 [thread=http-bio-8443-exec-7] [req=eb941534-31bd-4116-a687-3263630c82f2, org=ExampleTech, csid=] ERROR org.hibernate.engine.jdbc.spi.SqlExceptionHelper - An I/O error occurred while sending to the backend.
2020-05-22 11:58:28,328 [thread=http-bio-8443-exec-7] [req=eb941534-31bd-4116-a687-3263630c82f2, org=ExampleTech, csid=] WARN  com.mchange.v2.c3p0.impl.NewPooledConnection - [c3p0] A PooledConnection that has already signalled a Connection error is still in use!
2020-05-22 11:58:28,328 [thread=http-bio-8443-exec-7] [req=eb941534-31bd-4116-a687-3263630c82f2, org=ExampleTech, csid=] WARN  com.mchange.v2.c3p0.impl.NewPooledConnection - [c3p0] Another error has occurred [ org.postgresql.util.PSQLException: This connection has been closed. ] which will not be reported to listeners!
org.postgresql.util.PSQLException: This connection has been closed.
        at org.postgresql.jdbc.PgConnection.checkClosed(PgConnection.java:767)
        at org.postgresql.jdbc.PgConnection.rollback(PgConnection.java:774)
        at com.mchange.v2.c3p0.impl.NewProxyConnection.rollback(NewProxyConnection.java:1033)
        at org.hibernate.resource.jdbc.internal.AbstractLogicalConnectionImplementor.rollback(AbstractLogicalConnectionImplementor.java:116)
        at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.rollback(JdbcResourceLocalTransactionCoordinatorImpl.java:294)
        at org.hibernate.engine.transaction.internal.TransactionImpl.rollback(TransactionImpl.java:145)
Comment 1 Chris "Ceiu" Rog 2020-05-27 16:43:49 UTC 
The stack trace listed in comment #1 is not the source of the issue, but what occurs on repeated uses of the connection after it has been closed by the root cause here:

2020-05-26 19:02:20,322 [thread=QuartzScheduler_Worker-2] [job=import_81f894bc-c844-49af-811d-7932b487759d, org=Example, csid=] WARN  org.hibernate.engine.jdbc.spi.SqlExceptionHelper - SQL Error: 0, SQLState: 08006
2020-05-26 19:02:20,322 [thread=QuartzScheduler_Worker-2] [job=import_81f894bc-c844-49af-811d-7932b487759d, org=Example, csid=] ERROR org.hibernate.engine.jdbc.spi.SqlExceptionHelper - An I/O error occurred while sending to the backend.
2020-05-26 19:02:20,333 [thread=QuartzScheduler_Worker-2] [job=import_81f894bc-c844-49af-811d-7932b487759d, org=Example, csid=] ERROR org.candlepin.sync.Importer - Failed to import archive
javax.persistence.PersistenceException: org.hibernate.exception.JDBCConnectionException: 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.query.internal.AbstractProducedQuery.executeUpdate(AbstractProducedQuery.java:1604)
        at org.candlepin.model.AbstractHibernateCurator.bulkSQLDelete(AbstractHibernateCurator.java:1281)
        at org.candlepin.model.EntitlementCurator.batchDeleteByIds(EntitlementCurator.java:803)
        at org.candlepin.controller.CandlepinPoolManager.deletePools(CandlepinPoolManager.java:2277)
        at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(JpaLocalTxnInterceptor.java:62)
        at org.candlepin.controller.CandlepinPoolManager.deletePools(CandlepinPoolManager.java:2151)
        at org.candlepin.controller.CandlepinPoolManager.refreshPoolsWithRegeneration(CandlepinPoolManager.java:303)
        at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(JpaLocalTxnInterceptor.java:62)
        at org.candlepin.controller.Refresher.run(Refresher.java:163)
        at org.candlepin.sync.Importer.importObjects(Importer.java:610)
        at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(JpaLocalTxnInterceptor.java:62)
        at org.candlepin.sync.Importer.doExport(Importer.java:425)
        at org.candlepin.sync.Importer.loadStoredExport(Importer.java:207)
        at org.candlepin.controller.ManifestManager.importStoredManifest(ManifestManager.java:213)
        at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(JpaLocalTxnInterceptor.java:70)
        at org.candlepin.pinsetter.tasks.ImportJob.toExecute(ImportJob.java:80)
        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: org.hibernate.exception.JDBCConnectionException: could not execute statement
        at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:115)
        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.engine.query.spi.NativeSQLQueryPlan.performExecuteUpdate(NativeSQLQueryPlan.java:107)
        at org.hibernate.internal.SessionImpl.executeNativeUpdate(SessionImpl.java:1593)
        at org.hibernate.query.internal.NativeQueryImpl.doExecuteUpdate(NativeQueryImpl.java:292)
        at org.hibernate.query.internal.AbstractProducedQuery.executeUpdate(AbstractProducedQuery.java:1594)
        ... 18 common frames omitted
Caused by: org.postgresql.util.PSQLException: An I/O error occurred while sending to the backend.
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:333)
        at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:441)
        at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:365)
        at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:155)
        at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:132)
        at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:384)
        at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:175)
        ... 22 common frames omitted
Caused by: java.io.IOException: Tried to send an out-of-range integer as a 2-byte value: 56323
        at org.postgresql.core.PGStream.sendInteger2(PGStream.java:224)
        at org.postgresql.core.v3.QueryExecutorImpl.sendParse(QueryExecutorImpl.java:1440)
        at org.postgresql.core.v3.QueryExecutorImpl.sendOneQuery(QueryExecutorImpl.java:1762)
        at org.postgresql.core.v3.QueryExecutorImpl.sendQuery(QueryExecutorImpl.java:1326)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:298)
        ... 28 common frames omitted

This occurs when attempting to send a query with more parameters than the backend supports.
Comment 2 Barnaby Court 2020-05-29 14:28:45 UTC 
*** Bug 1841598 has been marked as a duplicate of this bug. ***