Note: This is a beta release of Red Hat Bugzilla 5.0. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Also email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback here.
Bug 1366607 - first registration to new satellite might fail when uploading package profile
Summary: first registration to new satellite might fail when uploading package profile
Keywords:
Status: CLOSED DEFERRED
Alias: None
Product: Red Hat Satellite 5
Classification: Red Hat
Component: Registration
Version: 570
Hardware: Unspecified
OS: Unspecified
unspecified
low
Target Milestone: ---
Assignee: Grant Gainey
QA Contact: Red Hat Satellite QA List
URL:
Whiteboard:
Depends On:
Blocks: sat5-rhn
TreeView+ depends on / blocked
 
Reported: 2016-08-12 12:39 UTC by Jan Hutař
Modified: 2018-04-09 16:09 UTC (History)
4 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2018-04-09 16:09:09 UTC


Attachments (Terms of Use)

Description Jan Hutař 2016-08-12 12:39:48 UTC
Description of problem:
First registration to new satellite might fail when uploading package profile - looks like something is not correctly initialized


Version-Release number of selected component (if applicable):
satellite-schema-5.7.0.24-1.el6sat.noarch
spacewalk-java-2.3.8-153.el6sat.noarch


How reproducible:
Seen this on 2 freshly installed satellites @PostgreSQL in row


Steps to Reproduce:
1. Install Satellite 5.7.0
2. Sync some packages
   # satellite-sync -c rhel-x86_64-server-6 -c rhn-tools-rhel-x86_64-server-6 -c rhel-x86_64-server-7 -c rhn-tools-rhel-x86_64-server-7 --no-rpms --no-packages --no-errata --no-kickstart
   # satellite-sync -c rhn-tools-rhel-x86_64-server-6 -c rhn-tools-rhel-x86_64-server-7
3. Take 10 systems and register them concurrently:
   # server=$( hostname )
   # cp -pr /etc/sysconfig/rhn{,.BACKUP}
   # wget -q -O /etc/sysconfig/rhn/RHN-ORG-TRUSTED-SSL-CERT https://$server/pub/RHN-ORG-TRUSTED-SSL-CERT --no-check-certificate || curl -o /etc/sysconfig/rhn/RHN-ORG-TRUSTED-SSL-CERT https://$server/pub/RHN-ORG-TRUSTED-SSL-CERT --insecure
   # echo "sslCACert=/etc/sysconfig/rhn/RHN-ORG-TRUSTED-SSL-CERT" >> /etc/sysconfig/rhn/up2date
   # echo "serverURL=https://$server/XMLRPC" >> /etc/sysconfig/rhn/up2date
   # rhnreg_ks --force --username=<user> --password=<pass>


Actual results:
For me, 9 of 10 registrations failed with:

An error has occurred:
Error communicating with server. The message was:
Internal Server Error
See /var/log/up2date for more information


Expected results:
Should pass (when I retry, it behaves nicely next time)

Comment 1 Jan Hutař 2016-08-12 12:40:22 UTC
Client's up2date log:

[Fri Aug 12 08:23:07 2016] up2date A protocol error occurred: Internal Server Error , attempt #1,
[Fri Aug 12 08:23:07 2016] up2date 
Traceback (most recent call last):
  File "/usr/sbin/rhnreg_ks", line 218, in <module>
    cli.run()
  File "/usr/share/rhn/up2date_client/rhncli.py", line 96, in run
    sys.exit(self.main() or 0)
  File "/usr/sbin/rhnreg_ks", line 151, in main
    rhnreg.sendPackages(systemId, packageList)
  File "/usr/share/rhn/up2date_client/rhnreg.py", line 482, in sendPackages
    s.registration.add_packages(systemId, packageList)
  File "/usr/share/rhn/up2date_client/rhnserver.py", line 63, in __call__
    return rpcServer.doCall(method, *args, **kwargs)
  File "/usr/share/rhn/up2date_client/rpcServer.py", line 204, in doCall
    ret = method(*args, **kwargs)
  File "/usr/lib64/python2.7/xmlrpclib.py", line 1233, in __call__
    return self.__send(self.__name, args)
  File "/usr/share/rhn/up2date_client/rpcServer.py", line 38, in _request1
    ret = self._request(methodname, params)
  File "/usr/lib/python2.7/site-packages/rhn/rpclib.py", line 384, in _request
    self._handler, request, verbose=self._verbose)
  File "/usr/lib/python2.7/site-packages/rhn/transports.py", line 171, in request
    headers, fd = req.send_http(host, handler)
  File "/usr/lib/python2.7/site-packages/rhn/transports.py", line 730, in send_http
    response.status, response.reason, response.msg)
<class 'up2date_client.up2dateErrors.CommunicationError'>: Error communicating with server. The message was:
Internal Server Error

Comment 3 Jan Hutař 2016-08-12 12:42:36 UTC
Server side:

==> /opt/rh/postgresql92/root/var/lib/pgsql/data/pg_log/postgresql-Fri.log <==
2016-08-12 08:23:06.099 EDT ERROR:  duplicate key value violates unique constraint "rhn_pn_name_uq"
2016-08-12 08:23:06.099 EDT DETAIL:  Key (name)=(iptables) already exists.
2016-08-12 08:23:06.099 EDT STATEMENT:  insert into rhnPackageName(id, name) values (47, 'iptables')
2016-08-12 08:23:06.114 EDT ERROR:  query returned no rows
2016-08-12 08:23:06.114 EDT CONTEXT:  PL/pgSQL function lookup_package_name(character varying,numeric) line 21 at SQL statement
2016-08-12 08:23:06.114 EDT STATEMENT:  
	            insert into rhnServerPackage
	            (server_id, name_id, evr_id, package_arch_id, installtime)
	            values (1000010004, LOOKUP_PACKAGE_NAME('iptables'), LOOKUP_EVR(NULL, '1.4.21', '16.el7'),
	                LOOKUP_PACKAGE_ARCH('x86_64'), TO_TIMESTAMP('2016-08-10 05:31:29', 'YYYY-MM-DD HH24:MI:SS')
	            )
	            
2016-08-12 08:23:06.116 EDT ERROR:  current transaction is aborted, commands ignored until end of transaction block
2016-08-12 08:23:06.116 EDT STATEMENT:  SELECT queue_server(1000010004, 0)
2016-08-12 08:23:06.491 EDT ERROR:  duplicate key value violates unique constraint "rhn_pn_name_uq"
2016-08-12 08:23:06.491 EDT DETAIL:  Key (name)=(util-linux) already exists.
2016-08-12 08:23:06.491 EDT STATEMENT:  insert into rhnPackageName(id, name) values (52, 'util-linux')
2016-08-12 08:23:06.502 EDT ERROR:  query returned no rows
2016-08-12 08:23:06.502 EDT CONTEXT:  PL/pgSQL function lookup_package_name(character varying,numeric) line 21 at SQL statement
2016-08-12 08:23:06.502 EDT STATEMENT:  
	            insert into rhnServerPackage
	            (server_id, name_id, evr_id, package_arch_id, installtime)
	            values (1000010003, LOOKUP_PACKAGE_NAME('util-linux'), LOOKUP_EVR(NULL, '2.23.2', '26.el7'),
	                LOOKUP_PACKAGE_ARCH('x86_64'), TO_TIMESTAMP('2016-08-10 05:32:23', 'YYYY-MM-DD HH24:MI:SS')
	            )
	            
2016-08-12 08:23:06.504 EDT ERROR:  current transaction is aborted, commands ignored until end of transaction block
2016-08-12 08:23:06.504 EDT STATEMENT:  SELECT queue_server(1000010003, 0)
2016-08-12 08:23:06.684 EDT ERROR:  duplicate key value violates unique constraint "rhn_pn_name_uq"
2016-08-12 08:23:06.684 EDT DETAIL:  Key (name)=(nss-tools) already exists.
2016-08-12 08:23:06.684 EDT STATEMENT:  insert into rhnPackageName(id, name) values (54, 'nss-tools')
2016-08-12 08:23:06.691 EDT ERROR:  query returned no rows
2016-08-12 08:23:06.691 EDT CONTEXT:  PL/pgSQL function lookup_package_name(character varying,numeric) line 21 at SQL statement
2016-08-12 08:23:06.691 EDT STATEMENT:  
	            insert into rhnServerPackage
	            (server_id, name_id, evr_id, package_arch_id, installtime)
	            values (1000010000, LOOKUP_PACKAGE_NAME('nss-tools'), LOOKUP_EVR(NULL, '3.19.1', '18.el7'),
	                LOOKUP_PACKAGE_ARCH('x86_64'), TO_TIMESTAMP('2016-08-10 05:31:07', 'YYYY-MM-DD HH24:MI:SS')
	            )
	            
2016-08-12 08:23:06.694 EDT ERROR:  current transaction is aborted, commands ignored until end of transaction block
2016-08-12 08:23:06.694 EDT STATEMENT:  SELECT queue_server(1000010000, 0)

Comment 4 Tomas Lestach 2016-08-12 15:22:10 UTC
Interesting, I thought, this is what should be handled by our lookup functions, like lookup_package_name.sql in this case:
 * select
 * insert if not found
   - in case the insert fails (as another process was faster), select again 
 * return

So, you see it with PG backend. Are you able to reproduce the same with ORA backend as well?

Comment 5 Jan Hutař 2016-08-12 20:00:01 UTC
No, this is only on PostgreSQL (have not seen it on Oracle in 2 attempts in row - same steps used).

Comment 6 Grant Gainey 2017-01-06 18:55:04 UTC
In postgres, this is accomplished with 

  schema/spacewalk/postgres/procs/lookup_package_name.sql

That code hasn't changed since 2012. Maybe we're finding a behavioral difference between Postgres9.2 and 9.5?

Comment 7 Grant Gainey 2017-01-06 21:26:14 UTC
Never mind, this is reported against 5.7, not 5.8 - so postgres9.5 isn't involved

Comment 8 Grant Gainey 2017-01-11 22:21:36 UTC
Testing status: 
 * Using the test-strategy from #c1 and 5 clients against a variety of satellites
 * 5.6: could NOT reproduce
 * 5.8/nightly: could NOT reproduce
 * 5.7 reproduced at will

Current thinking is that this is a Postgres-9.2-ism that only affects 5.7. More investigation required

Comment 10 Tomas Lestach 2018-04-09 16:09:09 UTC
We have re-reviewed this bug, as part of an ongoing effort to improve Satellite/Proxy feature and bug updates, review and backlog.

This is a low priority bug and has no currently open customer cases. While this bug may still valid, we do not see it being implemented prior to the EOL of the Satellite 5.x product. As such, this is being CLOSED DEFERRED. 

Closing now to help set customer expectations as early as possible. You are welcome to re-open this bug if needed.


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