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)
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
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)
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?
No, this is only on PostgreSQL (have not seen it on Oracle in 2 attempts in row - same steps used).
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?
Never mind, this is reported against 5.7, not 5.8 - so postgres9.5 isn't involved
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
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.