Bug 1132398

Summary: generating rhel-x86_64-server-5 repodata: java.lang.OutOfMemoryError: GC overhead limit exceeded
Product: Red Hat Satellite 5 Reporter: Jan Hutař <jhutar>
Component: ServerAssignee: Stephen Herr <sherr>
Status: CLOSED CURRENTRELEASE QA Contact: Pavel Studeník <pstudeni>
Severity: high Docs Contact:
Priority: high    
Version: 560CC: cperry, mmello, mtaru, nshaik, pdwyer, pgervase, pstudeni, sherr, tbily, tlestach, xdmoon
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: spacewalk-java-2.3.8-38 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 1141388 1166321 (view as bug list) Environment:
Last Closed: 2015-01-13 10:25:12 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:
Embargoed:
Bug Depends On:    
Bug Blocks: 1127215, 1141388, 1166321    

Description Jan Hutař 2014-08-21 09:43:56 UTC
Description of problem:
Generating rhel-x86_64-server-5 repodata causes "java.lang.OutOfMemoryError: GC overhead limit exceeded"


Version-Release number of selected component (if applicable):
Red Hat Satellite 5.6.0


How reproducible:
sometimes


Steps to Reproduce:
1. Sync rhel-x86_64-server-6 and rhel-x86_64-server-5 channels
   (I had a bunch of other channels on the system as well)


Actual results:
When watching /var/log/rhn/rhn_taskomatic_daemon.log, Taskomatic failed with "java.lang.OutOfMemoryError: GC overhead limit exceeded" while generating repodata.


Expected results:
Taskomatic should be able to generate repodata for RHEL5 and RHEL6 channels in default setup.


Additional info:
When I have followed https://access.redhat.com/solutions/43122, Taskomatic was able to generate repodata.

INFO   | jvm 1    | 2014/08/20 05:19:45 | 2014-08-20 05:19:45,262 [Thread-42] WARN  com.redhat.rhn.taskomatic.core.SchedulerKernel - Number of interrupted runs: 1
INFO   | jvm 1    | 2014/08/20 05:19:47 | 2014-08-20 05:19:47,627 [DefaultQuartzScheduler_Worker-3] INFO  com.redhat.rhn.taskomatic.task.ChannelRepodata - Resetting 2199 unfinished channel repodata tasks
INFO   | jvm 1    | 2014/08/20 05:19:47 | 2014-08-20 05:19:47,899 [DefaultQuartzScheduler_Worker-3] INFO  com.redhat.rhn.taskomatic.task.ChannelRepodata - In the queue: 2
INFO   | jvm 1    | 2014/08/20 05:19:49 | 2014-08-20 05:19:49,451 [Thread-53] INFO  com.redhat.rhn.taskomatic.task.repomd.RepositoryWriter - File Modified Date:1969-12-31 19:00:00 EST
INFO   | jvm 1    | 2014/08/20 05:19:49 | 2014-08-20 05:19:49,451 [Thread-53] INFO  com.redhat.rhn.taskomatic.task.repomd.RepositoryWriter - Channel Modified Date:2014-08-19 08:53:57 EDT
INFO   | jvm 1    | 2014/08/20 05:19:56 | 2014-08-20 05:19:56,254 [Thread-53] INFO  com.redhat.rhn.taskomatic.task.repomd.RepositoryWriter - Generating new repository metadata for channel 'rhel-x86_64-server-6'(sha256) 12831 packages, 2442 errata
INFO   | jvm 1    | 2014/08/20 05:21:14 | Exception in thread "Thread-53" 
INFO   | jvm 1    | 2014/08/20 05:21:15 | java.lang.OutOfMemoryError: GC overhead limit exceeded
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at org.postgresql.util.PGbytea.toBytes(PGbytea.java:91)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at org.postgresql.jdbc2.AbstractJdbc2ResultSet.getBytes(AbstractJdbc2ResultSet.java:2271)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at org.postgresql.jdbc2.AbstractJdbc2ResultSet.internalGetObject(AbstractJdbc2ResultSet.java:150)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at org.postgresql.jdbc3.AbstractJdbc3ResultSet.internalGetObject(AbstractJdbc3ResultSet.java:38)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at org.postgresql.jdbc4.AbstractJdbc4ResultSet.internalGetObject(AbstractJdbc4ResultSet.java:298)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at org.postgresql.jdbc2.AbstractJdbc2ResultSet.getObject(AbstractJdbc2ResultSet.java:2541)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at org.postgresql.jdbc2.AbstractJdbc2ResultSet.getObject(AbstractJdbc2ResultSet.java:2550)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at com.mchange.v2.c3p0.impl.NewProxyResultSet.getObject(NewProxyResultSet.java:1102)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at com.redhat.rhn.common.db.datasource.CachedStatement.getObject(CachedStatement.java:793)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at com.redhat.rhn.common.db.datasource.CachedStatement.addToObject(CachedStatement.java:776)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at com.redhat.rhn.common.db.datasource.CachedStatement.processResultSet(CachedStatement.java:626)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:474)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:443)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:345)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:351)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:287)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at com.redhat.rhn.common.db.datasource.SelectMode.execute(SelectMode.java:110)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at com.redhat.rhn.manager.task.TaskManager.getChannelPackageDtos(TaskManager.java:52)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at com.redhat.rhn.taskomatic.task.repomd.RpmRepositoryWriter.writeRepomdFiles(RpmRepositoryWriter.java:170)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at com.redhat.rhn.taskomatic.task.repomd.ChannelRepodataWorker.run(ChannelRepodataWorker.java:104)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:761)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 	at java.lang.Thread.run(Thread.java:745)
INFO   | jvm 1    | 2014/08/20 05:21:15 | 2014-08-20 05:21:15,366 [Thread-60] INFO  com.redhat.rhn.taskomatic.task.repomd.RepositoryWriter - File Modified Date:1969-12-31 19:00:00 EST
INFO   | jvm 1    | 2014/08/20 05:21:15 | 2014-08-20 05:21:15,366 [Thread-60] INFO  com.redhat.rhn.taskomatic.task.repomd.RepositoryWriter - Channel Modified Date:2014-08-18 09:24:30 EDT
INFO   | jvm 1    | 2014/08/20 05:21:18 | 2014-08-20 05:21:18,254 [Thread-60] INFO  com.redhat.rhn.taskomatic.task.repomd.RepositoryWriter - Generating new repository metadata for channel 'rhel-x86_64-server-5'(sha1) 16133 packages, 2941 errata
INFO   | jvm 1    | 2014/08/20 05:22:11 | Exception in thread "Thread-60" java.lang.OutOfMemoryError: GC overhead limit exceeded
INFO   | jvm 1    | 2014/08/20 05:22:11 | 	at java.lang.reflect.Method.copy(Method.java:151)
INFO   | jvm 1    | 2014/08/20 05:22:11 | 	at java.lang.reflect.ReflectAccess.copyMethod(ReflectAccess.java:136)
INFO   | jvm 1    | 2014/08/20 05:22:11 | 	at sun.reflect.ReflectionFactory.copyMethod(ReflectionFactory.java:300)
INFO   | jvm 1    | 2014/08/20 05:22:11 | 	at java.lang.Class.copyMethods(Class.java:2891)
INFO   | jvm 1    | 2014/08/20 05:22:11 | 	at java.lang.Class.getMethods(Class.java:1467)
INFO   | jvm 1    | 2014/08/20 05:22:11 | 	at com.redhat.rhn.common.db.datasource.CachedStatement.addToObject(CachedStatement.java:739)
INFO   | jvm 1    | 2014/08/20 05:22:11 | 	at com.redhat.rhn.common.db.datasource.CachedStatement.processResultSet(CachedStatement.java:626)
INFO   | jvm 1    | 2014/08/20 05:22:11 | 	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:474)
INFO   | jvm 1    | 2014/08/20 05:22:11 | 	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:443)
INFO   | jvm 1    | 2014/08/20 05:22:11 | 	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:345)
INFO   | jvm 1    | 2014/08/20 05:22:11 | 	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:351)
INFO   | jvm 1    | 2014/08/20 05:22:11 | 	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:287)
INFO   | jvm 1    | 2014/08/20 05:22:11 | 	at com.redhat.rhn.common.db.datasource.SelectMode.execute(SelectMode.java:110)
INFO   | jvm 1    | 2014/08/20 05:22:11 | 	at com.redhat.rhn.manager.task.TaskManager.getChannelPackageDtos(TaskManager.java:52)
INFO   | jvm 1    | 2014/08/20 05:22:11 | 	at com.redhat.rhn.taskomatic.task.repomd.RpmRepositoryWriter.writeRepomdFiles(RpmRepositoryWriter.java:170)
INFO   | jvm 1    | 2014/08/20 05:22:11 | 	at com.redhat.rhn.taskomatic.task.repomd.ChannelRepodataWorker.run(ChannelRepodataWorker.java:104)
INFO   | jvm 1    | 2014/08/20 05:22:11 | 	at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:756)
INFO   | jvm 1    | 2014/08/20 05:22:11 | 	at java.lang.Thread.run(Thread.java:745)

Comment 2 Stephen Herr 2014-08-27 17:52:41 UTC
In the process of fixing this I also discovered (and fixed) another problem:
In the updateinfo.xml.gz files the href entry for bugs in an erratum will be empty if the erratum doesn't have a url stored in the db. The correct behavior is for us to generate a bugzilla url based on the bug id.

Example:
Old (broken) xml:
<update from="" status="final" type="bugfix" version="1"><id>CL-BA-2013:0408</id><title>cifs-utils bug fix and enhancement update</title>...<references><reference href="" id="838606" type="bugzilla">enable PIE and RELRO in cifs-utils binaries</reference></references>...</update>

New (correct) xml:
<update from="" status="final" type="bugfix" version="1"><id>CL-BA-2013:0408</id><title>cifs-utils bug fix and enhancement update</title>...<references><reference href="http://bugzilla.redhat.com/bugzilla/show_bug.cgi?id=838606" id="838606" type="bugzilla">enable PIE and RELRO in cifs-utils binaries</reference></references>...</update>

Comment 5 Stephen Herr 2014-08-28 19:23:17 UTC
Committing to spacewalk master:
877f330803e62c7327bb852d9aee44f021ec9ab9

I have filed the issue in comment 2 as bug 1135073, however the same commit fixes both problems.

The new updateinfo.xml.gz will be different both because of the fix for 1135073 and because of a different ordering of the errata (hibernate's old ordering was non-specific, so I can't really recreate it), but in other respects the repomd files *should* be identical.

Comment 6 Stephen Herr 2014-08-28 19:25:56 UTC
Oh, I forgot to mention what this fix actually does.

Now instead of loading all packages into memory to write the repodata we only load 1000 at a time, so taskomatic's required memory size should no longer grow with channel size. I can successfully regenerate the repodata for rhel-x86_64-server-5 with taskomatic given a maxmemory of 512.

Comment 8 Stephen Herr 2014-10-13 19:34:16 UTC
Also needed (for debian repos), committing to Spacewalk master:
ef2946bcbc92012fbd8ea31368615d178bedb462

Comment 14 Clifford Perry 2015-01-13 10:25:12 UTC
With the release of Red Hat Satellite 5.7 on January 12th 2015 this bug is
being moved to a Closed Current Release state. 

The Satellite 5.7 GA Errata:
 - https://rhn.redhat.com/errata/RHSA-2015-0033.html 

Satellite 5.7 Release Notes:
 -
https://access.redhat.com/documentation/en-US/Red_Hat_Satellite/5.7/html-single/Release_Notes/index.html

Satellite Customer Portal Blog announcement for release:
 - https://access.redhat.com/blogs/1169563/posts/1315743 

Cliff

NOTE: This bug has not been re-verified (moved to RELEASE_PENDING) prior to release. We assume that the bug has indeed been fixed and not regressed since we initially verified it. Please re-open in the future if needed.

Comment 15 Tomas Lestach 2016-04-07 11:36:27 UTC
Making the BZ public as it does not contain any sensitive information.