[Spacewalk-list] Client updates failing

Thu Feb 18 21:16:30 UTC 2016

-----Original Message-----
From: Jan Hutař [mailto:jhutar at redhat.com] 
Sent: Thursday, February 18, 2016 4:10 PM
To: Dimitri Yioulos <dyioulos at netatlantic.com>
Cc: spacewalk-list at redhat.com
Subject: Re: [Spacewalk-list] Client updates failing

On 2016-02-18 20:19 +0000, Dimitri Yioulos wrote:
>Jan,
>
>Thanks for sticking with this!
>
>My apologies on getting the steps right.  This time I following them explicitly:
>
>1. stopped osad
>2. scheduled update
>3. ran "rhn_chceck -vv"
>
>[root at bluefield ~]# /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': 2743}
>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 1455826274.2 with expiration of 1455829874.2 seconds.
>successfully retrieved authentication token from up2date server
>D: logininfo:{'X-RHN-Server-Id': 1000010162, 'X-RHN-Auth-Server-Time': 
>'1455826275.39', 'X-RHN-Auth': 
>'l75aqjtpQW2aRJdb/2JuyI6B2EMQpfIpHtL35tinznI=', 'X-RHN-Auth-Channels': 
>[['centos5-x86_64', '20150219163429', '1', '1'], 
>['centos5-base-x86_64', '20160218040000', '0', '1'], 
>['centos5-updates-x86_64', '20160218070000', '0', '1'], 
>['epel5-x86_64', '20160218000000', '0', '1'], ['puppet-el5-x86_64', 
>'20160218100000', '0', '1'], ['rpmforge-el5-x86_64', '20160218020000', 
>'0', '1'], ['spacewalk-client-el5-x86_64', '20160218110000', '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': 2743}
>D: handle_action actionid = 2743, 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: centos.mia.host-engine.com
> * epel: mirror.steadfast.net
> * extras: mirrors.seas.harvard.edu
> * updates: mirror.cs.pitt.edu
>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
>
>Afterward, I saw this in the Event History of the node I was trying to update:
>
>Summary: Package Install scheduled by admin
>Details: This action will be executed after 2/18/16 3:11:00 PM EST This 
>action's status is: Failed.
>The client picked up this action on 2/18/16 3:11 PM The client 
>completed this action on 2/18/16 3:11 PM Client execution returned 
>"Fatal error in Python code occurred [[6]]" (code -1)
>
>Packages Scheduled:
>tzdata-2016a-1.el5.x86_64
>
>What the heck is going on here?
>
>Dimitri

Hmm, OK, some traceback ocurred. Please could you send content of /var/log/up2date from the client from around time you have ran the rhn_check (Thu Feb 18 15:11:14 EST 2016(?)). There should be a traceback showing what went wrong.

Regards,
Jan

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

Here we are:

[Thu Feb 18 15:11:14 2016] up2date 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></value>\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': 2743}
[Thu Feb 18 15:11:14 2016] up2date updateLoginInfo() login info
[Thu Feb 18 15:11:14 2016] up2date D: login(forceUpdate=True) invoked
[Thu Feb 18 15:11:14 2016] up2date logging into up2date server
[Thu Feb 18 15:11:14 2016] up2date D: rpcServer: Calling XMLRPC up2date.login
[Thu Feb 18 15:11:14 2016] up2date D: writeCachedLogin() invoked
[Thu Feb 18 15:11:14 2016] up2date D: Wrote pickled loginInfo at 1455826274.2 with expiration of 1455829874.2 seconds.
[Thu Feb 18 15:11:14 2016] up2date successfully retrieved authentication token from up2date server
[Thu Feb 18 15:11:14 2016] up2date D: logininfo:{'X-RHN-Server-Id': 1000010162, 'X-RHN-Auth-Server-Time': '1455826275.39', 'X-RHN-Auth': 'l75aqjtpQW2aRJdb/2JuyI6B2EMQpfIpHtL35tinznI=', 'X-RHN-Auth-Channels': [['centos5-x86_64', '20150219163429', '1', '1'], ['centos5-base-x86_64', '20160218040000', '0', '1'], ['centos5-updates-x86_64', '20160218070000', '0', '1'], ['epel5-x86_64', '20160218000000', '0', '1'], ['puppet-el5-x86_64', '20160218100000', '0', '1'], ['rpmforge-el5-x86_64', '20160218020000', '0', '1'], ['spacewalk-client-el5-x86_64', '20160218110000', '0', '1']], 'X-RHN-Auth-User-Id': '', 'X-RHN-Auth-Expire-Offset': '3600.0'}
[Thu Feb 18 15:11:14 2016] up2date 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></value>\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': 2743}
[Thu Feb 18 15:11:14 2016] up2date D: handle_action actionid = 2743, version = 2
[Thu Feb 18 15:11:14 2016] up2date D: do_call packages.update([['tzdata', '2016a', '1.el5', '', 'x86_64']],){'cache_only': None}
[Thu Feb 18 15:11:14 2016] up2date D: rpcServer: Calling XMLRPC up2date.listChannels
[Thu Feb 18 15:11:18 2016] up2date D: Called update[['tzdata', '2016a', '1.el5', '', 'x86_64']]
[Thu Feb 18 15:11:18 2016] up2date 
Traceback (most recent call last):
  File "/usr/sbin/rhn_check", line 359, in __run_action
    (status, message, data) = CheckCli.__do_call(method, params, kwargs)
  File "/usr/sbin/rhn_check", line 352, in __do_call
    retval = method(*params, **kwargs)
  File "/usr/share/rhn/actions/packages.py", line 347, in update
    print "Current:", current.epoch, current.version, current.release
exceptions.NameError: global name 'current' is not defined

[Thu Feb 18 15:11:18 2016] up2date D: Sending back response((6,), 'Fatal error in Python code occurred', {})
[Thu Feb 18 15:11:18 2016] up2date D: do_call packages.checkNeedUpdate('rhnsd=1',){}
[Thu Feb 18 15:11:18 2016] up2date D: local action status: (0, 'rpm database not modified since last update (or package list recently updated)', {})
[Thu Feb 18 15:11:18 2016] up2date D: rpcServer: Calling XMLRPC registration.welcome_message