+++ This bug was initially created as a clone of Bug #769908 +++

Description of problem:

the following scenario doesn't work:

http://docs.redhat.com/docs/en-US/Red_Hat_Network_Satellite/5.4/html-single/Proxy_Installation_Guide/index.html#sect-Proxy_Installation_Guide-Example_Topologies-Multiple_Proxy_Vertically_Tiered_Topology


Version-Release number of selected component (if applicable):

spacewalk-proxy-redirect-1.2.2-12.el6sat.noarch
spacewalk-proxy-broker-1.2.2-12.el6sat.noarch


How reproducible:

Always


Steps to Reproduce:

1. Setup a scenario with at least one tiered proxy (if a client is connected only trough one proxy to xmlrpc.rhn.redhat.com everthing works correctly):

RHEL5 client <-> Proxy num. 2 <-> Proxy num. 1 <-> xmlrpc.rhn.redhat.com

2. Do yum clean all and makecache (to let auth token create if it doesn't exist already) and wait 6 hours (default timeout) for token to expire or change the code to create tokens with lower offset

3. Run again yum clan all and makecache and you will see the 'Actual results'.

  
Actual results:

client# yum clean all
client# yum makecache
Loaded plugins: product-id, rhnplugin, security, subscription-manager
Updating Red Hat repositories.
Error: Cannot retrieve repository metadata (repomd.xml) for repository: redhat-rhn-proxy-5.4-server-x86_64-5. Please verify its path and try again
client#


Expected results:

the metadata should be created without the error

client# yum clean all
client# yum makecache
Loaded plugins: product-id, rhnplugin, security, subscription-manager
Updating Red Hat repositories.
redhat-rhn-proxy-5.4-server-x86_64-5                                                                                                                                                    | 1.3 kB     00:00     
redhat-rhn-proxy-5.4-server-x86_64-5/filelists                                                                                                                                          |  27 kB     00:00     
redhat-rhn-proxy-5.4-server-x86_64-5/updateinfo                                                                                                                                         |  10 kB     00:00     
redhat-rhn-proxy-5.4-server-x86_64-5/other                                                                                                                                              | 173 kB     00:00     
redhat-rhn-proxy-5.4-server-x86_64-5/primary
...


Additional info:

The code which regenerates the authentication tokens depends on 'X-RHN-Proxy-Auth-Error' header in the html reply for every method (GET, CONNECT, HEAD, PUT, POST):

spacewalk-proxy-1.2.2/broker/rhnBroker.py:
138     def handler(self):
...
215             respHeaders = self.responseContext.getHeaders()
216             if not respHeaders or \
217                not respHeaders.has_key('X-RHN-Proxy-Auth-Error'):
...
221                 break
222
223             # Expired/invalid auth token; go through the loop once again
224             error = string.split(respHeaders['X-RHN-Proxy-Auth-Error'], ':')[0]
225             if error == '1003': # invalid token
226                 msg = "RHN Proxy Session Token INVALID -- bad!"
227                 log_error(msg)
228                 log_debug(0, msg)
229             elif error == '1004':
230                 log_debug(1,
231                     "RHN Proxy Session Token expired, acquiring new one.")
232             else: # this should never happen.
233                 msg = "RHN Proxy login failed, error code is %s" % error
234                 log_error(msg)
235                 log_debug(0, msg)
236                 raise rhnFault(1000,
237                   _("RHN Proxy error (issues with proxy login). "
238                     "Please contact your system administrator."))
239 
240             # Forced refresh of the proxy token
241             rhnFlags.get('outputTransportOptions')['X-RHN-Proxy-Auth'] = self.proxyAuth.check_cached_token(1)

but it doesn't work for GET method which is the only one which gets redirected through squid to redirect component and then to xmlrpc.rhn.redhat.com, unfortunately the reply from squid/redirect component doesn't contain the original 'X-RHN-Proxy-Auth-Error' header sent by xmlrpc.rhn.redhat.com, but only squid headers so that tiered proxies don't get the error from 'X-RHN-Proxy-Auth-Error' header so they didn't regenerate the authentication token (the line #241 from above snippet doesn't get called) which leads to xmlrpc.rhn.redhat.com denying the client to proceed.

Look at reply from xmlrpc.rhn.redhat.com to proxy num. 1:

"""
GET http://xmlrpc.rhn.redhat.com/XMLRPC/GET-REQ/rhel-x86_64-server-5/repodata/repomd.xml HTTP/1.1
Host: xmlrpc.rhn.redhat.com
Accept-Encoding: identity
X-RHN-Auth-Expire-Offset: 3600.0
User-Agent: rhn.rpclib.py/$Revision: 190936 $
X-RHN-Auth-Server-Time: 1323859770.12
X-RHN-Transport-Capability: follow-redirects=3
Accept-Encoding: identity, identity, identity
X-RHN-Proxy-Version: 5.4.0
Connection: keep-alive
X-RHN-Auth: rMaSP<removed>wdK/apJA==
X-RHN-Proxy-Auth: 1021083084::1323365915.72:21600.0:Qwof8t3<removed>KNptdW4A==:<removed proxy num2hostname>,1021076977::1323859769.52:21600.0:Tmilqxu<removed>ntkqz3qWQ==:removed proxy num1hostname
Via: 1.1 <removed> (squid/3.1.10), 1.1 <removed> (squid/3.1.10)
X-RHN-Server-Id: 1021012641
Pragma: no-cache
X-Forwarded-For: <removed>,<removed>
X-RHN-Ip-Path: <removed>,<removed>
Cache-Control: max-age=31536000
X-RHN-Auth-User-Id: 

HTTP/1.1 404 Not Found
Via: 1.1 <removed>, 1.1 <removed>
Connection: Keep-Alive
Proxy-Connection: Keep-Alive
Content-Length: 1
Date: Wed, 14 Dec 2011 10:49:30 GMT
Content-Type: text/html; charset=iso-8859-1
Server: Apache
X-RHN-Fault-Code: -1004
X-RHN-Fault-String: CkVycm9yIENsYXNzIENvZGU6IDEwMDQKRXJyb3IgQ2xhc3MgSW5mbzogUkhOIFByb3h5IHNlc3Np
X-RHN-Fault-String: b24gdG9rZW4gaGFzIGV4cGlyZWQuCkV4cGxhbmF0aW9uOiAKICAgICBBbiBlcnJvciBoYXMgb2Nj
X-RHN-Fault-String: dXJyZWQgd2hpbGUgcHJvY2Vzc2luZyB5b3VyIHJlcXVlc3QuIElmIHRoaXMgcHJvYmxlbQogICAg
X-RHN-Fault-String: IHBlcnNpc3RzIHBsZWFzZSBlbnRlciBhIGJ1ZyByZXBvcnQgYXQgYnVnemlsbGEucmVkaGF0LmNv
X-RHN-Fault-String: bS4KICAgICBJZiB5b3UgY2hvb3NlIHRvIHN1Ym1pdCB0aGUgYnVnIHJlcG9ydCwgcGxlYXNlIGJl
X-RHN-Fault-String: IHN1cmUgdG8gaW5jbHVkZQogICAgIGRldGFpbHMgb2Ygd2hhdCB5b3Ugd2VyZSB0cnlpbmcgdG8g
X-RHN-Fault-String: ZG8gd2hlbiB0aGlzIGVycm9yIG9jY3VycmVkIGFuZAogICAgIGRldGFpbHMgb24gaG93IHRvIHJl
X-RHN-Fault-String: cHJvZHVjZSB0aGlzIHByb2JsZW0uCg==
X-RHN-Proxy-Version: 5.4.0
X-RHN-Proxy-Auth-Error: 1004:Expired
X-RHN-Client-Version: 0
"""

and the reply from the proxy num. 1 to proxy num. 2:

"""
GET /XMLRPC/GET-REQ/rhel-x86_64-server-5/repodata/repomd.xml HTTP/1.1
Host: <removed>
Accept-Encoding: identity
X-RHN-IP-Path: 10.219.4.18
User-Agent: rhn.rpclib.py/$Revision: 190936 $
X-RHN-Auth-Server-Time: 1323859765.48
X-RHN-Transport-Capability: follow-redirects=3
Pragma: no-cache
Accept-Encoding: identity
X-RHN-Auth-Expire-Offset: 3600.0
X-RHN-Proxy-Version: 5.4.0
X-RHN-Auth: mVky40SUhBkZtE0p14vXBQ==
X-RHN-Proxy-Auth: 1021083084::1323365915.72:21600.0:Qwof8t3<removed>KNptdW4A==:<removed proxy num2hostname>
X-RHN-Server-Id: 1021012641
X-RHN-Auth-User-Id: 
Via: 1.1 <removed> (squid/3.1.10)
X-Forwarded-For: 127.0.0.1
Cache-Control: max-age=31536000
Connection: keep-alive

HTTP/1.1 404 Not Found
Date: Wed, 14 Dec 2011 10:49:25 GMT
Server: Apache/2.2.15 (Red Hat)
Content-Length: 0
Connection: close
Content-Type: text/xml
"""

From above we can see that reply to the second proxy doesn't contain 'X-RHN-Proxy-Auth-Error'.

I added a debug statement (line #196) to proxy code to see what broker gets from redirect:

/usr/share/rhn/proxy/rhnShared.py:
177     def _serverCommo(self, data):
...
193         # Send the headers, the body and expect a response
194         try:
195             status, headers, bodyFd = self._proxy2server(data)
196             log_debug(2, "headers: %s" % headers)

and here it is:

xmlrpc.rhn.redhat.com -> redirect:

2011/12/19 13:46:59 -04:00 12608 10.34.35.100, 127.0.0.1: proxy/rhnShared._serverCommo('headers: Date: Mon, 19 Dec 2011 18:46:59 GMT\r\nServer: Apache\r\nX-RHN-Fault-Code: -1004\r\nX-RHN-Fault-String: CkVycm9yIENsYXNzIENvZGU6IDEwMDQKRXJyb3IgQ2xhc3MgSW5mbzogUkhOIFByb3h5IHNlc3Np\r\nX-RHN-Fault-String: b24gdG9rZW4gaGFzIGV4cGlyZWQuCkV4cGxhbmF0aW9uOiAKICAgICBBbiBlcnJvciBoYXMgb2Nj\r\nX-RHN-Fault-String: dXJyZWQgd2hpbGUgcHJvY2Vzc2luZyB5b3VyIHJlcXVlc3QuIElmIHRoaXMgcHJvYmxlbQogICAg\r\nX-RHN-Fault-String: IHBlcnNpc3RzIHBsZWFzZSBlbnRlciBhIGJ1ZyByZXBvcnQgYXQgYnVnemlsbGEucmVkaGF0LmNv\r\nX-RHN-Fault-String: bS4KICAgICBJZiB5b3UgY2hvb3NlIHRvIHN1Ym1pdCB0aGUgYnVnIHJlcG9ydCwgcGxlYXNlIGJl\r\nX-RHN-Fault-String: IHN1cmUgdG8gaW5jbHVkZQogICAgIGRldGFpbHMgb2Ygd2hhdCB5b3Ugd2VyZSB0cnlpbmcgdG8g\r\nX-RHN-Fault-String: ZG8gd2hlbiB0aGlzIGVycm9yIG9jY3VycmVkIGFuZAogICAgIGRldGFpbHMgb24gaG93IHRvIHJl\r\nX-RHN-Fault-String: cHJvZHVjZSB0aGlzIHByb2JsZW0uCg==\r\nX-RHN-Proxy-Version: 5.4.0\r\nX-RHN-Proxy-Auth-Error: 1004:Expired\r\nX-RHN-Client-Version: 0\r\nContent-Length: 1\r\nContent-Type: text/html; charset=iso-8859-1\r\nConnection: close\r\n',)

redirect -> broker:

2011/12/19 13:46:59 -04:00 12610 10.34.35.100: proxy/rhnShared._serverCommo('headers: Date: Mon, 19 Dec 2011 18:46:59 GMT\r\nServer: Apache/2.2.15 (Red Hat)\r\nContent-Length: 0\r\nContent-Type: text/xml\r\nX-Cache: MISS from tyan-gt24-11.rhts.eng.bos.redhat.com\r\nX-Cache-Lookup: MISS from tyan-gt24-11.rhts.eng.bos.redhat.com:8080\r\nVia: 1.0 tyan-gt24-11.rhts.eng.bos.redhat.com (squid/3.1.10)\r\nConnection: keep-alive\r\n',)

I can see that a code which gets called straight after a code which obtains a results from parent proxy that it adds the error headers, but there is no routine which would send them back to the broker even the comment mentions:

"By default, we will wrap all the headers up and send them back to the client with an error status.":

Yes, it will wrap them but won't send them:

spacewalk-proxy-1.2.2/rhnShared.py:
219     def _handleServerResponse(self, status):
220         """ This method can be overridden by subclasses who want to handle server
221             responses in their own way.  By default, we will wrap all the headers up
222             and send them back to the client with an error status.  This method
223             should return apache.OK if everything went according to plan.
224         """
225         if (status != apache.HTTP_OK) and (status != apache.HTTP_PARTIAL_CONTENT):
226             # Non 200 response; have to treat it differently
227             log_debug(2, "Forwarding status %s" % status)
228             # Copy the incoming headers to err_headers_out
229             headers = self.responseContext.getHeaders()
230             if headers is not None:
231                 for k in headers.keys():
232                     rhnLib.setHeaderValue(self.req.err_headers_out, k,
233                         self._get_header(k))

I tried to add the following, but although it works correctly for passing the headers from redirect to broker, it doesn't work correctly between two proxies in case the proxy returns correct results/HTTP_OK:

diff -up /usr/share/rhn/proxy/rhnShared.py.orig /usr/share/rhn/proxy/rhnShared.py
--- /usr/share/rhn/proxy/rhnShared.py.orig      2011-12-22 11:43:52.150335792 -0500
+++ /usr/share/rhn/proxy/rhnShared.py   2011-12-22 11:44:00.817662510 -0500
@@ -231,6 +231,8 @@ class SharedHandler:
                 for k in headers.keys():
                     rhnLib.setHeaderValue(self.req.err_headers_out, k,
                         self._get_header(k))
+                bodyFd = self.responseContext.getBodyFd()
+                self._forwardHTTPHeaders(bodyFd, self.req)
             else:
                 log_error('WARNING? - no incoming headers found!')
             # And that's that


Temporary workaround:

regularly remove contents of /var/cache/rhn/proxy-auth directory on every proxy server except the top level one. It could be achieved by adding the following line into /etc/crontab (+service crond restart):

0 */4 * * * root rm -rf /var/cache/rhn/proxy-auth/*

It will remove contents of that directory every 4 hours (the default timeout is 6 hours). If the command is called directly on the command line, it will fix his problem immediately.

--- Additional comment from mosvald on 2011-12-22 16:03:46 EST ---

the following demonstrates the problem more clearly (auth token doesn't get regenerated after 6 hours, the same auth token is cached for several days):

# grep "auth token for this machine only" rhn_proxy_broker.log:
...
2011/12/09 15:04:43 +02:00 1576 <ip>: broker/rhnBroker.handler('XXX auth token for this machine only! 1021083084::1323365915.72:21600.0:Qwof8t3yuPmLBwKNptdW4A==:proxynum2',)
...
2011/12/14 11:49:30 +02:00 12632 <ip>: broker/rhnBroker.handler('XXX auth token for this machine only! 1021083084::1323365915.72:21600.0:Qwof8t3yuPmLBwKNptdW4A==:proxynum2',)

--- Additional comment from sherr on 2012-08-14 17:14:39 EDT ---

To reproduce in a time less than 6 hours change the default timeout values for creating client auth tokens. To do so on the Satellite:
In /usr/share/rhn/config-defaults/rhn_server_iss.conf:
satellite_auth_timeout = 60.0 # one minute
In /usr/share/rhn/config-defaults/rhn_server.conf:
client_auth_timeout = 60.0 # one minute
proxy_auth_timeout = 60.0 # one minute

Note: to reproduce you must be using SSL for the proxies.

I feel confident that I will be able to finish tracking this problem back to its source tomorrow.

--- Additional comment from sherr on 2012-08-15 13:10:54 EDT ---

Okay, here is the problem written out as a conversation:

client -> proxy1 -> proxy2 -> satellite

1) client: I want this thing.
2) proxy1: I'll forward this on for you and attach my auth token.
3) proxy2: I'll forward this on for you and attach my auth tokan (in addition to the one that already is there).
4) satellite: 404, your auth token is expired.
5) proxy2: Oh thanks, I'll update my auth token.
6) proxy2: Now that that's taken care of, here's the request again. I'll add my new auth token to the one that's already there.
7) satellite: 404, Your auth token is expired.
8) proxy2: Oh thanks, I'll update my auth token.
9) proxy2: Well, I tried 2 times and got a 404 each time so it must not be an auth token problem, let's return the 404 to the user. Let's also helpfully clear out these nasty auth token error headers.
10) proxy 1: Looks like I got a 404, but it doesn't say there's anything wrong with my auth token so it must be fine. I'll return this to the user.
11) client: Oh no! 404!

This happens regardless of whether we are using SSL or not, the only difference is that when we're not using SSL the Satellite instead of sending a 404 will send the requested content because it doesn't matter that the auth token is invalid, so the client will actually get the content he requested.

What I have done is:
1) Updated the Satellite so that when it says "your auth token is expired" we include the hostname of the proxy that needs to update its auth token.
2) Updated the proxies to look at the hostname, and if the message is not meant for me pass it on up.

This problem could also exist if a Proxy's auth token is invalid (corrupted) and not just expired, which is a different error; 1003. I have fixed it there as well.