Bug 1455167

Summary: Provisioning of a client through RHN proxy fail
Product: Red Hat Satellite 5 Reporter: Martin Korbel <mkorbel>
Component: ProvisioningAssignee: Jan Dobes <jdobes>
Status: CLOSED WONTFIX QA Contact: Red Hat Satellite QA List <satqe-list>
Severity: high Docs Contact:
Priority: high    
Version: 570CC: jhutar, rdrazny, tlestach
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-07-13 15:03:51 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1391420, 1450111    

Description Martin Korbel 2017-05-24 12:11:02 UTC 
Description of problem:
provisioning of a client throught RHN proxy (in my case 5.7) fail with errors. I have tested RHN Proxy 5.8 and installation passed successfully.

Version-Release number of selected component (if applicable):
spacewalk-backend-2.3.3-48.el6sat.noarch
spacewalk-proxy-package-manager-2.3.0-6.el6sat.noarch

How reproducible:
100%

Steps to Reproduce:
1. We have got Sat5.7/5.8, RHN Proxy 5.7 and the client machine RHEL7, which are registred to satellite.
2. We create kickstart profile (in my case RHEL7)
3. Enable RHN Tools channel and Provisioning entitlements on the client
4. Schedule re-provisioning of the client throught RHN proxy
5. Check booting process

Actual results:
...
Warning: Downloading 'http://fqdn/ty/hash/LiveOS/squashfs.img' failed!



RHN Proxy 
> tailf  /var/log/httpd/error_log
...
[Wed May 24 07:21:11 2017] [error] Exception reported from proxy57-el6.example.com
[Wed May 24 07:21:11 2017] [error] Time: Wed May 24 07:21:11 2017
[Wed May 24 07:21:11 2017] [error] Exception type <type 'exceptions.TypeError'>
[Wed May 24 07:21:11 2017] [error] Exception while handling function headerParserHandler
[Wed May 24 07:21:11 2017] [error] Request object information:
[Wed May 24 07:21:11 2017] [error] URI: /ty/kKpR6XK4/LiveOS/squashfs.img
[Wed May 24 07:21:11 2017] [error] Remote Host: host-8-177-113.host.centralci.eng.rdu2.redhat.com
[Wed May 24 07:21:11 2017] [error] Server Name: proxy57-el6.example.com:80
[Wed May 24 07:21:11 2017] [error] Headers passed in:
[Wed May 24 07:21:11 2017] [error] \tAccept: */*
[Wed May 24 07:21:11 2017] [error] \tDOCUMENT_ROOT: /var/www/html
[Wed May 24 07:21:11 2017] [error] \tGATEWAY_INTERFACE: CGI/1.1
[Wed May 24 07:21:11 2017] [error] \tHTTP_ACCEPT: */*
[Wed May 24 07:21:11 2017] [error] \tHTTP_HOST: proxy57-el6.example.com
[Wed May 24 07:21:11 2017] [error] \tHTTP_USER_AGENT: curl/7.29.0
[Wed May 24 07:21:11 2017] [error] \tHTTP_X_ANACONDA_ARCHITECTURE: x86_64
[Wed May 24 07:21:11 2017] [error] \tHTTP_X_ANACONDA_SYSTEM_RELEASE: Red Hat Enterprise Linux
[Wed May 24 07:21:11 2017] [error] \tHTTP_X_RHN_PROVISIONING_MAC_0: eth0 fa:16:3e:22:e8:fe
[Wed May 24 07:21:11 2017] [error] \tHost: proxy57-el6.example.com
[Wed May 24 07:21:11 2017] [error] \tPATH_INFO: /kKpR6XK4/LiveOS/squashfs.img
[Wed May 24 07:21:11 2017] [error] \tPATH_TRANSLATED: /var/www/html/kKpR6XK4/LiveOS/squashfs.img
[Wed May 24 07:21:11 2017] [error] \tQUERY_STRING: 
[Wed May 24 07:21:11 2017] [error] \tREMOTE_ADDR: 10.8.177.113
[Wed May 24 07:21:11 2017] [error] \tREMOTE_PORT: 45542
[Wed May 24 07:21:11 2017] [error] \tREQUEST_METHOD: GET
[Wed May 24 07:21:11 2017] [error] \tREQUEST_URI: /ty/kKpR6XK4/LiveOS/squashfs.img
[Wed May 24 07:21:11 2017] [error] \tSCRIPT_FILENAME: /usr/share/rhn/wsgi/xmlrpc.py
[Wed May 24 07:21:11 2017] [error] \tSCRIPT_NAME: /ty
[Wed May 24 07:21:11 2017] [error] \tSCRIPT_URI: http://proxy57-el6.example.com/ty/kKpR6XK4/LiveOS/squashfs.img
[Wed May 24 07:21:11 2017] [error] \tSCRIPT_URL: /ty/kKpR6XK4/LiveOS/squashfs.img
[Wed May 24 07:21:11 2017] [error] \tSERVER_ADDR: 172.16.20.190
[Wed May 24 07:21:11 2017] [error] \tSERVER_ADMIN: root@localhost
[Wed May 24 07:21:11 2017] [error] \tSERVER_NAME: proxy57-el6.example.com
[Wed May 24 07:21:11 2017] [error] \tSERVER_PORT: 80
[Wed May 24 07:21:11 2017] [error] \tSERVER_PROTOCOL: HTTP/1.1
[Wed May 24 07:21:11 2017] [error] \tSERVER_SIGNATURE: <address>Apache/2.2.15 (Red Hat) Server at proxy57-el6.example.com Port 80</address>
[Wed May 24 07:21:11 2017] [error] 
[Wed May 24 07:21:11 2017] [error] \tSERVER_SOFTWARE: Apache/2.2.15 (Red Hat)
[Wed May 24 07:21:11 2017] [error] \tUser-Agent: curl/7.29.0
[Wed May 24 07:21:11 2017] [error] \tX-Anaconda-Architecture: x86_64
[Wed May 24 07:21:11 2017] [error] \tX-Anaconda-System-Release: Red Hat Enterprise Linux
[Wed May 24 07:21:11 2017] [error] \tX-RHN-Provisioning-Mac-0: eth0 fa:16:3e:22:e8:fe
[Wed May 24 07:21:11 2017] [error] \tmod_ssl.is_https: <built-in method ssl_is_https of mod_wsgi.Adapter object at 0x7fbdfc00ec60>
[Wed May 24 07:21:11 2017] [error] \tmod_ssl.var_lookup: <built-in method ssl_var_lookup of mod_wsgi.Adapter object at 0x7fbdfc00ec60>
[Wed May 24 07:21:11 2017] [error] \tmod_wsgi.application_group: host-8-176-27.host.centralci.eng.rdu2.redhat.com|/ty
[Wed May 24 07:21:11 2017] [error] \tmod_wsgi.callable_object: application
[Wed May 24 07:21:11 2017] [error] \tmod_wsgi.handler_script: 
[Wed May 24 07:21:11 2017] [error] \tmod_wsgi.input_chunked: 0
[Wed May 24 07:21:11 2017] [error] \tmod_wsgi.listener_host: 
[Wed May 24 07:21:11 2017] [error] \tmod_wsgi.listener_port: 80
[Wed May 24 07:21:11 2017] [error] \tmod_wsgi.process_group: 
[Wed May 24 07:21:11 2017] [error] \tmod_wsgi.request_handler: wsgi-script
[Wed May 24 07:21:11 2017] [error] \tmod_wsgi.script_reloading: 1
[Wed May 24 07:21:11 2017] [error] \tmod_wsgi.version: (3, 2)
[Wed May 24 07:21:11 2017] [error] \twsgi.errors: <mod_wsgi.Log object at 0x7fbdfc085630>
[Wed May 24 07:21:11 2017] [error] \twsgi.file_wrapper: <built-in method file_wrapper of mod_wsgi.Adapter object at 0x7fbdfc00ec60>
[Wed May 24 07:21:11 2017] [error] \twsgi.input: <mod_wsgi.Input object at 0x7fbdfc0855f0>
[Wed May 24 07:21:11 2017] [error] \twsgi.multiprocess: True
[Wed May 24 07:21:11 2017] [error] \twsgi.multithread: False
[Wed May 24 07:21:11 2017] [error] \twsgi.run_once: False
[Wed May 24 07:21:11 2017] [error] \twsgi.url_scheme: http
[Wed May 24 07:21:11 2017] [error] \twsgi.version: (1, 1)
[Wed May 24 07:21:11 2017] [error] Extra information about this error:
[Wed May 24 07:21:11 2017] [error] Unhandled exception type
[Wed May 24 07:21:11 2017] [error] 
[Wed May 24 07:21:11 2017] [error] Exception Handler Information
[Wed May 24 07:21:11 2017] [error] Traceback (most recent call last):
[Wed May 24 07:21:11 2017] [error]   File "/usr/share/rhn/proxy/apacheServer.py", line 62, in __call__
[Wed May 24 07:21:11 2017] [error]     ret = f(req)
[Wed May 24 07:21:11 2017] [error]   File "/usr/share/rhn/proxy/apacheHandler.py", line 113, in headerParserHandler
[Wed May 24 07:21:11 2017] [error]     ret = self._transformKickstartRequest(req)
[Wed May 24 07:21:11 2017] [error]   File "/usr/share/rhn/proxy/apacheHandler.py", line 145, in _transformKickstartRequest
[Wed May 24 07:21:11 2017] [error]     return self._transformKsRequestForBroker(req)
[Wed May 24 07:21:11 2017] [error]   File "/usr/share/rhn/proxy/apacheHandler.py", line 157, in _transformKsRequestForBroker
[Wed May 24 07:21:11 2017] [error]     (status, checksum) = self._querySatelliteForChecksum(req)
[Wed May 24 07:21:11 2017] [error]   File "/usr/share/rhn/proxy/apacheHandler.py", line 246, in _querySatelliteForChecksum
[Wed May 24 07:21:11 2017] [error]     connection.request("HEAD", pingURL, None, hdrs)
[Wed May 24 07:21:11 2017] [error]   File "/usr/lib64/python2.6/httplib.py", line 973, in request
[Wed May 24 07:21:11 2017] [error]     self._send_request(method, url, body, headers)
[Wed May 24 07:21:11 2017] [error]   File "/usr/lib64/python2.6/httplib.py", line 1009, in _send_request
[Wed May 24 07:21:11 2017] [error]     self.putheader(hdr, value)
[Wed May 24 07:21:11 2017] [error]   File "/usr/lib64/python2.6/httplib.py", line 952, in putheader
[Wed May 24 07:21:11 2017] [error]     value = '%s' % value
[Wed May 24 07:21:11 2017] [error] TypeError: not all arguments converted during string formatting
[Wed May 24 07:21:11 2017] [error]


Expected results:
No errors


Additional info:

The problem is with converting of the attribute wsgi.version: (1, 1), which is tuple and converting to string is problem.
Comment 1 Pavel Studeník 2017-06-06 14:24:01 UTC 
Problem arises only when the Proxy 5.6/5.7 is used with Satellite 5.8
Comment 3 Pavel Studeník 2017-06-06 15:50:42 UTC 
The problem was fixed in spacewalk by the patch 687cd5695744d1e54a17738224a0d0309b70560c
Comment 9 Pavel Studeník 2017-06-07 11:45:44 UTC 
I downgrade RHEL6 to following packages:

python-2.6.6-64.el6.x86_64
httpd-2.2.15-59.el6.x86_64
mod_wsgi-3.2-6.el6_5.x86_64

And the provisioning works through this proxy.
Comment 10 Tomas Lestach 2017-06-07 12:02:51 UTC 
Pavel confirmed patch mentioned in Comment#3 fixes this problem.

Switching the BZ to MODIFIED, since we have a patch in upstream.
Comment 11 Pavel Studeník 2017-06-07 12:34:01 UTC 
Probably it will need more than one fix. I receive this errors:

>> /var/log/httpd/access_log
192.168.122.67 - - [07/Jun/2017:08:31:06 -0400] "GET /ty/Jo6V6sE2/images/install.img HTTP/1.1" 500 - "-" "anaconda/13.21.254"

>> /var/log/rhn/rhn_proxy_broker.log
2017/06/07 08:31:07 -04:00 28173 127.0.0.1: proxy/rhnShared._serverCommo('HTTP status code (200 means all is well): 500',)
2017/06/07 08:31:07 -04:00 28173 127.0.0.1: proxy/rhnShared._handleServerResponse('Forwarding status 500',)
2017/06/07 08:31:07 -04:00 28173 127.0.0.1: broker/rhnBroker.handler('Leaving handler with status code 500',)
2017/06/07 08:31:07 -04:00 28173 127.0.0.1: proxy/apacheHandler.handler('Leaving with status code 500',)
2017/06/07 08:31:07 -04:00 28173 127.0.0.1: common/rhnApache.logHandler
2017/06/07 08:31:07 -04:00 28173 127.0.0.1: proxy/apacheHandler.cleanupHandler
2017/06/07 08:31:07 -04:00 28173 127.0.0.1: common/rhnApache.cleanupHandler
2017/06/07 08:31:07 -04:00 28173 127.0.0.1: common/rhnApache.timer('Request served in 1.13 sec',)
2017/06/07 08:31:07 -04:00 28178 192.168.122.67: proxy/apacheHandler._querySatelliteForChecksum('Received response status: 500',)
2017/06/07 08:31:07 -04:00 28178 192.168.122.67: proxy/apacheHandler._querySatelliteForChecksum('HEAD req - Received error code in reponse: 500',)
Comment 12 Tomas Lestach 2017-06-08 13:10:46 UTC 
Based on Comment 11, switching back to NEW.