[Spacewalk-list] Sync profile failure
Coe, Colin C. (Unix Engineer)
Colin.Coe at woodside.com.au
Fri Oct 3 14:36:55 UTC 2008
Anything interesting in /var/log/tomcat5/catalina.out or /var/log/httpd/error_log?
CC
________________________________
From: spacewalk-list-bounces at redhat.com [spacewalk-list-bounces at redhat.com] On Behalf Of puck at i29.net [puck at i29.net]
Sent: Friday, 3 October 2008 10:34 PM
To: spacewalk-list at redhat.com
Subject: Re: [Spacewalk-list] Sync profile failure
I realized after sending that last message that I didn't include enough information. Here is the result of a rhn-profile-sync:
[root at rhn ~]# rhn-profile-sync -vvv
updateLoginInfo() login info
D: login(forceUpdate=True) invoked
D: opening db environment /var/lib/rpm/Packages joinenv
D: opening db index /var/lib/rpm/Packages rdonly mode=0x0
D: locked db index /var/lib/rpm/Packages
D: opening db index /var/lib/rpm/Providename rdonly mode=0x0
logging into up2date server
D: writeCachedLogin() invoked
D: Wrote pickled loginInfo at 1223043347.21 with expiration of 1223046947.21 seconds.
successfully retrieved authentication token from up2date server
D: logininfo: {'X-RHN-Server-Id': 1000010127, 'X-RHN-Auth-Server-Time': '1223043347.2', 'X-RHN-Auth': 'VSwy2U4NUYZJNugO9X/fgQ==', 'X-RHN-Auth-Channels': [['centos-5-i386', '20080926021247', '1', '1']], 'X-RHN-Auth-User-Id': '', 'X-RHN-Auth-Expire-Offset': '3600.0'}
Updating package profile...
Updating package profile
A protocol error occurred: Internal Server Error , attempt #1,
A protocol error occurred: Internal Server Error , attempt #2,
A protocol error occurred: Internal Server Error , attempt #3,
A protocol error occurred: Internal Server Error , attempt #4,
A protocol error occurred: Internal Server Error , attempt #5,
An error has occurred:
Internal Server Error
Error communicating with server. The message was:
Internal Server Error
See /var/log/up2date for more information
D: closed db index /var/lib/rpm/Providename
D: closed db index /var/lib/rpm/Packages
D: closed db environment /var/lib/rpm/Packages
D: May free Score board((nil))
And the accompanying rhn_server_xmlrpc.log output:
2008/10/03 09:15:46 -05:00 29456 10.0.1.166: rhnSQL/int_oracle.check_connection('ERROR', "DATABASE CONNECTION TO 'xe' LOST", "Exception information: (3114, 'ORA-03114: not connected to ORACLE\\n', 'select sysdate as ID from dual')")
2008/10/03 09:15:46 -05:00 29456 10.0.1.166: rhnSQL/int_oracle.connect('Connecting to database', 'xe')
2008/10/03 09:15:47 -05:00 29456 10.0.1.166: xmlrpc/up2date.login(1000010127,)
2008/10/03 09:15:47 -05:00 29449 10.0.1.166: xmlrpc/registration.update_packages(1000010127, 'packages: 657')
2008/10/03 09:16:19 -05:00 30019 10.0.1.166: xmlrpc/registration.update_packages(1000010127, 'packages: 657')
2008/10/03 09:18:25 -05:00 29453 10.0.1.166: rhnSQL/int_oracle.check_connection('ERROR', "DATABASE CONNECTION TO 'xe' LOST", "Exception information: (3114, 'ORA-03114: not connected to ORACLE\\n', 'select sysdate as ID from dual')")
2008/10/03 09:18:25 -05:00 29453 10.0.1.166: rhnSQL/int_oracle.connect('Connecting to database', 'xe')
2008/10/03 09:18:25 -05:00 29453 10.0.1.166: xmlrpc/registration.update_packages(1000010127, 'packages: 657')
2008/10/03 09:24:41 -05:00 29457 10.0.1.166: rhnSQL/int_oracle.check_connection('ERROR', "DATABASE CONNECTION TO 'xe' LOST", "Exception information: (3114, 'ORA-03114: not connected to ORACLE\\n', 'select sysdate as ID from dual')")
2008/10/03 09:24:41 -05:00 29457 10.0.1.166: rhnSQL/int_oracle.connect('Connecting to database', 'xe')
2008/10/03 09:24:41 -05:00 29457 10.0.1.166: xmlrpc/registration.update_packages(1000010127, 'packages: 657')
2008/10/03 09:29:22 -05:00 29591 10.0.1.166: rhnSQL/int_oracle.check_connection('ERROR', "DATABASE CONNECTION TO 'xe' LOST", "Exception information: (3114, 'ORA-03114: not connected to ORACLE\\n', 'select sysdate as ID from dual')")
2008/10/03 09:29:22 -05:00 29591 10.0.1.166: rhnSQL/int_oracle.connect('Connecting to database', 'xe')
2008/10/03 09:29:22 -05:00 29591 10.0.1.166: xmlrpc/up2date.listChannels(1000010127,)
2008/10/03 09:29:22 -05:00 29450 10.0.1.166: rhnSQL/int_oracle.check_connection('ERROR', "DATABASE CONNECTION TO 'xe' LOST", "Exception information: (3114, 'ORA-03114: not connected to ORACLE\\n', 'select sysdate as ID from dual')")
2008/10/03 09:29:22 -05:00 29450 10.0.1.166: rhnSQL/int_oracle.connect('Connecting to database', 'xe')
2008/10/03 09:29:55 -05:00 30540 10.0.1.166: rhnSQL/int_oracle.check_connection('ERROR', "DATABASE CONNECTION TO 'xe' LOST", "Exception information: ('Can not prepare statement', (3114, 'ORA-03114: not connected to ORACLE', ''))")
2008/10/03 09:29:55 -05:00 30540 10.0.1.166: rhnSQL/int_oracle.connect('Connecting to database', 'xe')
2008/10/03 09:29:57 -05:00 30540 10.0.1.166: xmlrpc/registration.update_packages(1000010127, 'packages: 657')
Jem Tallon
puck at i29.net<mailto:puck at i29.net> wrote:
I'm having this exact same issue. rhn_register seems to be able to create a profile but causes errors when trying to populate the package list. I also receive the errors below when I use rhn_check or rhn-profile-sync on a client. yum-rhn works fine and downloads updates, then those packages that were updated are added to the package list. Any ideas what might be causing this?
*** Log file from running "rhn-profile-sync" then "yum update" ***
2008/10/03 08:47:37 -05:00 29451 10.0.1.166: xmlrpc/up2date.login(1000010127,)
2008/10/03 08:47:37 -05:00 29457 10.0.1.166: xmlrpc/up2date.listChannels(1000010127,)
2008/10/03 08:48:02 -05:00 29591 10.0.1.166: rhnSQL/int_oracle.check_connection('ERROR', "DATABASE CONNECTION TO 'xe' LOST", "Exception information: ('Can not prepare statement', (3114, 'ORA-03114: not connected to ORACLE', ''))")
2008/10/03 08:48:02 -05:00 29591 10.0.1.166: rhnSQL/int_oracle.connect('Connecting to database', 'xe')
2008/10/03 08:48:02 -05:00 29450 10.0.1.166: rhnSQL/int_oracle.check_connection('ERROR', "DATABASE CONNECTION TO 'xe' LOST", "Exception information: ('Can not prepare statement', (3114, 'ORA-03114: not connected to ORACLE', ''))")
2008/10/03 08:48:02 -05:00 29450 10.0.1.166: rhnSQL/int_oracle.connect('Connecting to database', 'xe')
2008/10/03 08:48:02 -05:00 30019 10.0.1.166: rhnSQL/int_oracle.check_connection('ERROR', "DATABASE CONNECTION TO 'xe' LOST", "Exception information: (3114, 'ORA-03114: not connected to ORACLE\\n', 'select sysdate as ID from dual')")
2008/10/03 08:48:02 -05:00 30019 10.0.1.166: rhnSQL/int_oracle.connect('Connecting to database', 'xe')
2008/10/03 08:48:02 -05:00 29452 10.0.1.166: rhnSQL/int_oracle.check_connection('ERROR', "DATABASE CONNECTION TO 'xe' LOST", "Exception information: ('Can not prepare statement', (3114, 'ORA-03114: not connected to ORACLE', ''))")
2008/10/03 08:48:02 -05:00 29452 10.0.1.166: rhnSQL/int_oracle.connect('Connecting to database', 'xe')
2008/10/03 08:48:12 -05:00 29592 10.0.1.166: rhnSQL/int_oracle.check_connection('ERROR', "DATABASE CONNECTION TO 'xe' LOST", "Exception information: (3114, 'ORA-03114: not connected to ORACLE\\n', 'select sysdate as ID from dual')")
2008/10/03 08:48:12 -05:00 29592 10.0.1.166: rhnSQL/int_oracle.connect('Connecting to database', 'xe')
2008/10/03 08:48:12 -05:00 29592 10.0.1.166: xmlrpc/registration.delta_packages(1000010127, 'added: 6')
2008/10/03 08:48:14 -05:00 29590 10.0.1.166: xmlrpc/up2date.listChannels(1000010127,)
2008/10/03 08:48:36 -05:00 29449 10.0.1.166: xmlrpc/up2date.listChannels(1000010127,)
2008/10/03 08:48:56 -05:00 29455 10.0.1.166: xmlrpc/up2date.login(1000010127,)
2008/10/03 08:48:56 -05:00 29591 10.0.1.166: xmlrpc/registration.update_packages(1000010127, 'packages: 657')
2008/10/03 08:49:04 -05:00 29450 10.0.1.166: xmlrpc/registration.update_packages(1000010127, 'packages: 657')
2008/10/03 08:49:11 -05:00 30019 10.0.1.166: xmlrpc/registration.update_packages(1000010127, 'packages: 657')
2008/10/03 08:50:13 -05:00 29452 10.0.1.166: xmlrpc/registration.update_packages(1000010127, 'packages: 657')
2008/10/03 08:51:18 -05:00 29778 10.0.1.166: xmlrpc/registration.update_packages(1000010127, 'packages: 657')
Jem Tallon
________________________________
* From: "Jason Frisvold" <xenophage0 gmail com>
* To: spacewalk-list redhat com
* Subject: [Spacewalk-list] Sync profile failure
* Date: Tue, 23 Sep 2008 09:58:45 -0400
________________________________
Hi there,
I'm getting an error when trying to sync my server profile with
Spacewalk. This started when 0.2 was installed. As a result, the
systems overview page doesn't reflect the current status of the system
correctly, showing packages that need to be installed. If you choose
details on a specific system, however, the details page shows
everything up to date.
This information is from the up2date log on the client system:
[Tue Sep 23 09:31:48 2008] up2date updateLoginInfo() login info
[Tue Sep 23 09:31:49 2008] up2date logging into up2date server
[Tue Sep 23 09:31:51 2008] up2date successfully retrieved
authentication token from up2date server
[Tue Sep 23 09:31:51 2008] up2date Updating package profile
[Tue Sep 23 09:31:57 2008] up2date A protocol error occurred: Internal
Server Error , attempt #1,
[Tue Sep 23 09:32:18 2008] up2date A protocol error occurred: Internal
Server Error , attempt #2,
[Tue Sep 23 09:33:15 2008] up2date A protocol error occurred: Internal
Server Error , attempt #3,
[Tue Sep 23 09:34:12 2008] up2date A protocol error occurred: Internal
Server Error , attempt #4,
[Tue Sep 23 09:36:03 2008] up2date A protocol error occurred: Internal
Server Error , attempt #5,
[Tue Sep 23 09:36:03 2008] up2date Error communicating with server.
The message was:
Internal Server Error
[Tue Sep 23 09:36:03 2008] up2date
Traceback (most recent call last):
File "/usr/sbin/rhn-profile-sync", line 54, in ?
cli.run()
File "/usr/share/rhn/up2date_client/rhncli.py", line 65, in run
sys.exit(self.main() or 0)
File "/usr/sbin/rhn-profile-sync", line 42, in main
rhnPackageInfo.updatePackageProfile()
File "/usr/share/rhn/up2date_client/rhnPackageInfo.py", line 27, in
updatePackageProfile
rpmUtils.getInstalledPackageList(getArch=1))
File "/usr/share/rhn/up2date_client/rhnserver.py", line 50, in __call__
return rpcServer.doCall(method, *args, **kwargs)
File "/usr/share/rhn/up2date_client/rpcServer.py", line 263, in doCall
raise up2dateErrors.CommunicationError(e.errmsg)
up2date_client.up2dateErrors.CommunicationError: Error communicating
with server. The message was:
Internal Server Error
On the Spacewalk server, I have the following in the rhn_server_xmlrpc.log file:
2008/09/23 09:48:19 -04:00 21923 192.168.1.1:
rhnSQL/int_oracle.check_connection('ERROR', "DATABASE CONNECTION TO
'xe' LOST", "Exception information: (3114, 'ORA-03114: not connected
to ORACLE\\n', 'select sysdate as ID from dual')")
2008/09/23 09:48:19 -04:00 21923 192.168.1.1:
rhnSQL/int_oracle.connect('Connecting to database', 'xe')
2008/09/23 09:48:19 -04:00 21923 192.168.1.1: xmlrpc/up2date.login(1000010000,)
2008/09/23 09:48:20 -04:00 30476 192.168.1.1:
rhnSQL/int_oracle.check_connection('ERROR', "DATABASE CONNECTION TO
'xe' LOST", "Exception information: ('Can not prepare statement',
(3114, 'ORA-03114: not connected to ORACLE', ''))")
2008/09/23 09:48:20 -04:00 30476 192.168.1.1:
rhnSQL/int_oracle.connect('Connecting to database', 'xe')
2008/09/23 09:48:21 -04:00 30476 192.168.1.1:
xmlrpc/registration.update_packages(1000010000, 'packages: 653')
So it appears that Oracle is to blame (again) ... I looked at the
oracle status during this transaction and I have the following :
[root dev rhn]# /sbin/service oracle-xe status
LSNRCTL for Linux: Version 10.2.0.1.0 - Production on 23-SEP-2008 09:49:07
Copyright (c) 1991, 2005, Oracle. All rights reserved.
Connecting to (DESCRIPTION=(ADDRESS=(PROTOCOL=IPC)(KEY=EXTPROC_FOR_XE)))
STATUS of the LISTENER
------------------------
Alias LISTENER
Version TNSLSNR for Linux: Version 10.2.0.1.0 - Production
Start Date 19-SEP-2008 16:12:01
Uptime 3 days 17 hr. 37 min. 6 sec
Trace Level off
Security ON: Local OS Authentication
SNMP OFF
Default Service XE
Listener Parameter File
/usr/lib/oracle/xe/app/oracle/product/10.2.0/server/network/admin/listener.ora
Listener Log File
/usr/lib/oracle/xe/app/oracle/product/10.2.0/server/network/log/listener.log
Listening Endpoints Summary...
(DESCRIPTION=(ADDRESS=(PROTOCOL=ipc)(KEY=EXTPROC_FOR_XE)))
(DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=dev.example.com)(PORT=1521)))
(DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=127.0.0.1)(PORT=9000))(Presentation=HTTP)(Session=RAW))
Services Summary...
Service "PLSExtProc" has 1 instance(s).
Instance "PLSExtProc", status UNKNOWN, has 1 handler(s) for this service...
Service "XE" has 1 instance(s).
Instance "XE", status READY, has 1 handler(s) for this service...
Service "XEXDB" has 1 instance(s).
Instance "XE", status READY, has 1 handler(s) for this service...
Service "XE_XPT" has 1 instance(s).
Instance "XE", status READY, has 1 handler(s) for this service...
The command completed successfully
I'm not familiar with Oracle, so I could use some assistance. Is the
above problem caused by the single handler instance? Can that be
increased? Or is it something else causing the problem?
Thanks!
--
Jason 'XenoPhage' Frisvold
XenoPhage0 gmail com
http://blog.godshell.com
________________________________
_______________________________________________
Spacewalk-list mailing list
Spacewalk-list at redhat.com<mailto:Spacewalk-list at redhat.com>
https://www.redhat.com/mailman/listinfo/spacewalk-list
NOTICE: This email and any attachments are confidential.
They may contain legally privileged information or
copyright material. You must not read, copy, use or
disclose them without authorisation. If you are not an
intended recipient, please contact us at once by return
email and then delete both messages and all attachments.
More information about the Spacewalk-list
mailing list