[Spacewalk-list] Sync profile failure

puck at i29.net puck at i29.net
Fri Oct 3 14:34:39 UTC 2008


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 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
> https://www.redhat.com/mailman/listinfo/spacewalk-list
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/spacewalk-list/attachments/20081003/69cba117/attachment.htm>


More information about the Spacewalk-list mailing list