[Spacewalk-list] Client updates failing

Dimitri Yioulos dyioulos at netatlantic.com
Tue Feb 16 21:40:51 UTC 2016



-----Original Message-----
From: Jan Hutař [mailto:jhutar at redhat.com] 
Sent: Tuesday, February 16, 2016 4:14 PM
To: Dimitri Yioulos <dyioulos at netatlantic.com>
Cc: spacewalk-list at redhat.com; Wesley Owen <wes at netatlantic.com>
Subject: Re: [Spacewalk-list] Client updates failing

On 2016-02-16 19:44 +0000, Dimitri Yioulos wrote:
[...]
>>Hello,
>>I'm not sure if the outputs you have sent matches. According to timestampt in `rhn_check -vv` output, it was executed at 09:07:36, but text you have copy&pasted from Spacewalk webUI says 9:57.
>>
>>Cold you please try with osad stopped?:
>>
>>  1. client# service osad stop
>>  2. on Spacewalk schedule package upgrade  3. client# rhn_check -vv
>>
>>And if output seems reasonable similar to whats in refferenced bug, try with change from:
>>
>>  https://bugzilla.redhat.com/show_bug.cgi?id=1302198#c1
>>
>>  1. client# service osad stop
>>  2. on Spacewalk schedule package upgrade  3. client# cp 
>> /usr/share/rhn/actions/packages.py{,.ORIG}
>>  4. client# vim /usr/share/rhn/actions/packages.py   # add these 3
>>               lines, make sure to preserve indentation  5. client# 
>> rhn_check -vv  6. client# cp 
>> /usr/share/rhn/actions/packages.py{.ORIG,}
>>
>>Also please provide info about currently installed tzdata package:
>>
>>  client# rpm -q tzdata --qf "%{NAME}-%{EPOCH}:%{VERSION}-%{RELEASE}.%{ARCH}\n"
>>
>>and package you are trying to update to:
>>
>>  spacewalk# rpm -qp /where/is/tzdata-...rpm --qf 
>> "%{NAME}-%{EPOCH}:%{VERSION}-%{RELEASE}.%{ARCH}\n"
>>
>>Thank you in advance,
>>Jan
>>
>>
>>
>>--
>>Jan Hutar     Systems Management QA
>>jhutar at redhat.com     Red Hat, Inc.
>>
>>
>>Hi, Jan.
>>
>>This bug is similar, and I posted to it:
>>https://bugzilla.redhat.com/show_bug.cgi?id=1248713
>>
>>Here's the output of rhn_check after stopping the osad client, and scheduling a package update in Spacewalk:
>>
>>[root at server ~]# /sbin/service osad stop
>>Shutting down osad:                                        [  OK  ]
>>
>>[root at server ~]# /usr/sbin/rhn_check -vv
>>D: check_action{'action': "<?xml
>>version='1.0'?>\n<methodCall>\n<methodName>packages.update</methodName
>>> 
>>\n<params>\n<param>\n<value><array><data>\n<value><array><data>\n<valu
>>e
>>><string>tzdata</string></value>\n<value><string>2016a</string></value
>>>>
>>\n<value><string>1.el5</string></value>\n<value><string></string></val
>>u
>>e>\n<value><string>x86_64</string></value>\n</data></array></value>\n<
>>e>/
>>data></array></value>\n</param>\n</params>\n</methodCall>\n",
>>'version': 2, 'id': 2738}
>>updateLoginInfo() login info
>>D: login(forceUpdate=True) invoked
>>logging into up2date server
>>D: rpcServer: Calling XMLRPC up2date.login
>>D: writeCachedLogin() invoked
>>D: Wrote pickled loginInfo at 1455630131.72 with expiration of 1455633731.72 seconds.
>>successfully retrieved authentication token from up2date server
>>D: logininfo:{'X-RHN-Server-Id': 1000010162, 'X-RHN-Auth-Server-Time':
>>'1455630132.38', 'X-RHN-Auth':
>>'jSQKwscXgB12m2VTlF90h0xFgqQCz0BBNULqmVMYLaE=', 'X-RHN-Auth-Channels':
>>[['centos5-x86_64', '20150219163429', '1', '1'], 
>>['centos5-base-x86_64', '20160215172513', '0', '1'], 
>>['centos5-updates-x86_64', '20160215181106', '0', '1'], 
>>['epel5-x86_64', '20160215181856', '0', '1'], ['puppet-el5-x86_64', 
>>'20160213002732', '0', '1'], ['rpmforge-el5-x86_64', '20160215131156', 
>>'0', '1'], ['spacewalk-client-el5-x86_64', '20160215175220', '0', 
>>'1']], 'X-RHN-Auth-User-Id': '', 'X-RHN-Auth-Expire-Offset': '3600.0'}
>>D: handle_action{'action': "<?xml
>>version='1.0'?>\n<methodCall>\n<methodName>packages.update</methodName
>>> 
>>\n<params>\n<param>\n<value><array><data>\n<value><array><data>\n<valu
>>e
>>><string>tzdata</string></value>\n<value><string>2016a</string></value
>>>>
>>\n<value><string>1.el5</string></value>\n<value><string></string></val
>>u
>>e>\n<value><string>x86_64</string></value>\n</data></array></value>\n<
>>e>/
>>data></array></value>\n</param>\n</params>\n</methodCall>\n",
>>'version': 2, 'id': 2738}
>>D: handle_action actionid = 2738, version = 2
>>D: do_call packages.update([['tzdata', '2016a', '1.el5', '',
>>'x86_64']],){'cache_only': None} Loaded plugins: fastestmirror, 
>>rhnplugin
>>D: rpcServer: Calling XMLRPC up2date.listChannels This system is 
>>receiving updates from RHN Classic or Red Hat Satellite.
>>Loading mirror speeds from cached hostfile
>> * base: mirror.atlanticmetro.net
>> * epel: mirrors.rit.edu
>> * extras: centos.mirror.nac.net
>> * updates: mirror.trouble-free.net
>>Reducing Extra Packages for Enterprise Linux 5 - x86_64 to included 
>>packages only Finished Checking for new repos for mirrors
>>D: Called update[['tzdata', '2016a', '1.el5', '', 'x86_64']]
>>D: More recent version of package tzdata-0:2016a-1.el5.x86_64 is 
>>already installed
>>D: Sending back response(0, 'Requested packages already installed', 
>>{})
>>D: do_call packages.checkNeedUpdate('rhnsd=1',){}
>>D: local action status: (0, 'rpm database not modified since last 
>>update (or package list recently updated)', {})
>>D: rpcServer: Calling XMLRPC registration.welcome_message
>>
>>And the output from checking on which tzdata package is installed, and which I'm trying to update to:
>>
>>[root at server ~]# rpm -q tzdata --qf "%{NAME}-%{EPOCH}:%{VERSION}-%{RELEASE}.%{ARCH}\n"
>>tzdata-(none):2015g-1.el5.x86_64
>>
>>[root at server ~]# rpm -qa|grep tzdata
>>tzdata-2015g-1.el5
>>
>>[root at server ~]# rpm -qp http://mirror.centos.org/centos/5/updates/i386/RPMS/tzdata-java-2016a-1.el5.i386.rpm --qf "%{NAME}-%{EPOCH}:%{VERSION}-%{RELEASE}.%{ARCH}\n"
>>tzdata-java-(none):2016a-1.el5.i386
>
>Hello.
>
>I guess this is a typo and you meant:
>
>$ rpm -qp http://mirror.centos.org/centos/5/updates/i386/RPMS/tzdata-2016a-1.el5.i386.rpm --qf "%{NAME}-%{EPOCH}:%{VERSION}-%{RELEASE}.%{ARCH}\n"
>tzdata-(none):2016a-1.el5.i386
>
>(BTW: huh, did not knew rpm can handle packages on http://... for 
>queries as well, thanks)
>
>>When I do a manual update via yum on a similar system:
>>
>>Updated:
>>  tzdata.x86_64 0:2016a-1.el5
>>
>>And the output of rpm -qa|grep tzdata is the same.
>>
>>From you previous post, I'm not sure which three lines you're referring to in:
>>
>>  4. client# vim /usr/share/rhn/actions/packages.py   # add these 3
>>               lines, make sure to preserve indentation
>>
>>Dimitri
>
>Err, you are right, there are 4 lines:
>
>  https://bugzilla.redhat.com/show_bug.cgi?id=1302198#c1
>
>(these prefixed with "+" - add them to the location of /usr/share/rhn/actions/packages.py as you can see there (without that leading plus sign).
>
>Regards,
>Jan
>
>
>
>-- 
>Jan Hutar     Systems Management QA
>jhutar at redhat.com     Red Hat, Inc.
>
>
>Jan,
>
>After backing up/modifying packages.py as follows:
>
>        found = False
>        for pkg in pkgs:
>            print "Current:", current.epoch, current.version, current.release
>            print "Candidate:", evr.epoch, evr.version, evr.release
>            print "Comparasion:", current.compare(evr)
>            if pkg.returnEVR().compare(evr) == 0:
>                log.log_debug('Package %s already installed' \
>                    % _yum_package_tup(package))
>           ~
>
>I ran rhn_check, with the following output:
>
>[root at server actions]# /usr/sbin/rhn_check -vv
>D: check_action{'action': "<?xml 
>version='1.0'?>\n<methodCall>\n<methodName>packages.update</methodName>
>\n<params>\n<param>\n<value><array><data>\n<value><array><data>\n<value
>><string>tzdata</string></value>\n<value><string>2016a</string></value>
>\n<value><string>1.el5</string></value>\n<value><string></string></valu
>e>\n<value><string>x86_64</string></value>\n</data></array></value>\n</
>data></array></value>\n</param>\n</params>\n</methodCall>\n", 
>'version': 2, 'id': 2739}
>updateLoginInfo() login info
>D: login(forceUpdate=True) invoked
>logging into up2date server
>D: rpcServer: Calling XMLRPC up2date.login
>D: writeCachedLogin() invoked
>D: Wrote pickled loginInfo at 1455646702.53 with expiration of 1455650302.53 seconds.
>successfully retrieved authentication token from up2date server
>D: logininfo:{'X-RHN-Server-Id': 1000010162, 'X-RHN-Auth-Server-Time': 
>'1455646703.57', 'X-RHN-Auth': 
>'sZm51YnvCfQzwXsCTshBPfpBxhhT9xkRb9NubPX098Q=', 'X-RHN-Auth-Channels': 
>[['centos5-x86_64', '20150219163429', '1', '1'], 
>['centos5-base-x86_64', '20160215172513', '0', '1'], 
>['centos5-updates-x86_64', '20160215181106', '0', '1'], 
>['epel5-x86_64', '20160215181856', '0', '1'], ['puppet-el5-x86_64', 
>'20160213002732', '0', '1'], ['rpmforge-el5-x86_64', '20160215131156', 
>'0', '1'], ['spacewalk-client-el5-x86_64', '20160215175220', '0', 
>'1']], 'X-RHN-Auth-User-Id': '', 'X-RHN-Auth-Expire-Offset': '3600.0'}
>D: handle_action{'action': "<?xml 
>version='1.0'?>\n<methodCall>\n<methodName>packages.update</methodName>
>\n<params>\n<param>\n<value><array><data>\n<value><array><data>\n<value
>><string>tzdata</string></value>\n<value><string>2016a</string></value>
>\n<value><string>1.el5</string></value>\n<value><string></string></valu
>e>\n<value><string>x86_64</string></value>\n</data></array></value>\n</
>data></array></value>\n</param>\n</params>\n</methodCall>\n", 
>'version': 2, 'id': 2739}
>D: handle_action actionid = 2739, version = 2
>D: do_call packages.update([['tzdata', '2016a', '1.el5', '', 
>'x86_64']],){'cache_only': None} Loaded plugins: fastestmirror, 
>rhnplugin
>D: rpcServer: Calling XMLRPC up2date.listChannels This system is receiving updates from RHN Classic or Red Hat Satellite.
>Loading mirror speeds from cached hostfile
> * base: mirror.atlanticmetro.net
> * epel: mirror.vcu.edu
> * extras: mirror.trouble-free.net
> * updates: mirror.netdepot.com
>Reducing Extra Packages for Enterprise Linux 5 - x86_64 to included 
>packages only Finished Checking for new repos for mirrors
>D: Called update[['tzdata', '2016a', '1.el5', '', 'x86_64']]
>Current: D: Sending back response((6,), 'Fatal error in Python code 
>occurred', {})
>D: do_call packages.checkNeedUpdate('rhnsd=1',){}
>D: local action status: (0, 'rpm database not modified since last 
>update (or package list recently updated)', {})
>D: rpcServer: Calling XMLRPC registration.welcome_message
>
>Dimitri
>
>
>Since adding the lines in packages.py, I see the following in the Spacewalk UI:
>
>Details: This action will be executed after 2/16/16 1:13:00 PM EST This 
>action's status is: Failed.
>The client picked up this action on 2/16/16 1:18 PM The client 
>completed this action on 2/16/16 1:18 PM Client execution returned 
>"Fatal error in Python code occurred [[6]]" (code -1)
>
>Packages Scheduled:
>tzdata-2016a-1.el5.x86_64
>
>Dimitri

Hello.

Details about his "Fatal error in Python code occurred" should be logged on client in /var/log/up2date.

Also please restart your Spacewalk after this change in the code (but you have probably already done that).

Regards,
Jan



-- 
Jan Hutar     Systems Management QA
jhutar at redhat.com     Red Hat, Inc.


Oops, I actually hadn't restarted the Spacewalk server after changing the code in the client.  After doing so, I stopped osad on the client, and ran rhn_check:

[root at server ~]# /usr/sbin/rhn_check -vv
D: do_call packages.checkNeedUpdate('rhnsd=1',){}
Loaded plugins: fastestmirror, rhnplugin
D: login(forceUpdate=False) invoked
D: readCachedLogin invoked
D: Checking pickled loginInfo, currentTime=1455657841.6, createTime=1455646702.53, expire-offset=3600.0
D: Pickled loginInfo has expired, created = 1455646702.53, expire = 1455650302.53.
logging into up2date server
D: rpcServer: Calling XMLRPC up2date.login
D: writeCachedLogin() invoked
D: Wrote pickled loginInfo at 1455657841.63 with expiration of 1455661441.63 seconds.
successfully retrieved authentication token from up2date server
D: logininfo:{'X-RHN-Server-Id': 1000010162, 'X-RHN-Auth-Server-Time': '1455657842.92', 'X-RHN-Auth': 'x8Ca4i9/NXvPC+OuoInP44M1JGiuyr2aYiks1BKbQhY=', 'X-RHN-Auth-Channels': [['centos5-x86_64', '20150219163429', '1', '1'], ['centos5-base-x86_64', '20160215172513', '0', '1'], ['centos5-updates-x86_64', '20160215181106', '0', '1'], ['epel5-x86_64', '20160215181856', '0', '1'], ['puppet-el5-x86_64', '20160213002732', '0', '1'], ['rpmforge-el5-x86_64', '20160215131156', '0', '1'], ['spacewalk-client-el5-x86_64', '20160215175220', '0', '1']], 'X-RHN-Auth-User-Id': '', 'X-RHN-Auth-Expire-Offset': '3600.0'}
D: rpcServer: Calling XMLRPC up2date.listChannels
This system is receiving updates from RHN Classic or Red Hat Satellite.
Loading mirror speeds from cached hostfile
 * base: mirror.atlanticmetro.net
 * epel: mirrors.mit.edu
 * extras: mirror.trouble-free.net
 * updates: mirrors.seas.harvard.edu
Reducing Extra Packages for Enterprise Linux 5 - x86_64 to included packages only
Finished
Checking for new repos for mirrors
D: local action status: (0, 'rpm database not modified since last update (or package list recently updated)', {})
D: rpcServer: Calling XMLRPC registration.welcome_message
[root at bluefield ~]# tail -f /var/log/up2date
[Tue Feb 16 16:24:01 2016] up2date D: Pickled loginInfo has expired, created = 1455646702.53, expire = 1455650302.53.
[Tue Feb 16 16:24:01 2016] up2date logging into up2date server
[Tue Feb 16 16:24:01 2016] up2date D: rpcServer: Calling XMLRPC up2date.login
[Tue Feb 16 16:24:01 2016] up2date D: writeCachedLogin() invoked
[Tue Feb 16 16:24:01 2016] up2date D: Wrote pickled loginInfo at 1455657841.63 with expiration of 1455661441.63 seconds.
[Tue Feb 16 16:24:01 2016] up2date successfully retrieved authentication token from up2date server
[Tue Feb 16 16:24:01 2016] up2date D: logininfo:{'X-RHN-Server-Id': 1000010162, 'X-RHN-Auth-Server-Time': '1455657842.92', 'X-RHN-Auth': 'x8Ca4i9/NXvPC+OuoInP44M1JGiuyr2aYiks1BKbQhY=', 'X-RHN-Auth-Channels': [['centos5-x86_64', '20150219163429', '1', '1'], ['centos5-base-x86_64', '20160215172513', '0', '1'], ['centos5-updates-x86_64', '20160215181106', '0', '1'], ['epel5-x86_64', '20160215181856', '0', '1'], ['puppet-el5-x86_64', '20160213002732', '0', '1'], ['rpmforge-el5-x86_64', '20160215131156', '0', '1'], ['spacewalk-client-el5-x86_64', '20160215175220', '0', '1']], 'X-RHN-Auth-User-Id': '', 'X-RHN-Auth-Expire-Offset': '3600.0'}
[Tue Feb 16 16:24:01 2016] up2date D: rpcServer: Calling XMLRPC up2date.listChannels
[Tue Feb 16 16:24:06 2016] up2date D: local action status: (0, 'rpm database not modified since last update (or package list recently updated)', {})
[Tue Feb 16 16:24:06 2016] up2date D: rpcServer: Calling XMLRPC registration.welcome_message

I restarted osad on the client, then tried to do an update from the Spacewalk server.  I watched the output of top, and saw rhn_check try to run three or four times, but always go to "rhn_check <defunct>"

Dimitri




More information about the Spacewalk-list mailing list